Repository: salopensource/sal
Issue: Checkin causes sporadic IntegrityError exceptions

**Describe the bug**
When clients checkin, Sal processes their ManagedInstalls, and the results of any current installs or removals. Because some of this data does not include dates, Sal provides a date based on the checkin time. This unfortunately creates `UpdateHistoryItem` objects that are out-of-sequence when `sort_by('recorded')` is used later to determine whether to create new items. The checkin script then plows ahead with creating an item that will then fail the uniqueness requirements of the `UpdateHistoryItem` model.

**To Reproduce**
I'm not 100% I can create this situation manually in anything but a synthetic way, but I see it in my fleet.
1. A new Munki install enters the environment.
2. I'm a little fuzzy on how this happens, but a pending UHI and an install UHI get created. Incorrectly, the pending has a younger `recorded`.
3. On the next checkin, for some reason the ManagedInstallReport still has an install result entry. (I guess this is because Sal is checking in more frequently than Munki?) Since it doesn't sort last, the current Sal code then tries to create a new one.
4. When the items are bulk saved, psycopg throws the exception.

**Expected behavior**
Sal should create the pending with an earlier dt than a subsequent install. But Munki doesn't put this data in, so we're stuck guessing. I'll look at using the Munki run start time rather than the Sal checkin time.

Also, checkin will currently create a "pending" UHI for installed software. I guess I did this so there wouldn't be an empty history. I think that was a mistake.

**Screenshots**
NA

**Server (please complete the following information):**
 - Host environment: Docker
 - Version: 3.3.11

**Additional context**
(exception is from the py3 branch, but it's the same in master)
ERROR:django.request:Internal Server Error: /checkin/
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/django/db/backends/utils.py", line 64, in execute
    return self.cursor.execute(sql, params)
psycopg2.IntegrityError: duplicate key value violates unique constraint "server_updatehistoryite_update_history_id_78bcc0ce2c3b29f0_uniq"
DETAIL:  Key (update_history_id, recorded, status)=(649395, 2018-11-12 19:56:35+00, install) already exists.


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.6/site-packages/django/core/handlers/exception.py", line 39, in inner
    response = get_response(request)
  File "/usr/local/lib/python3.6/site-packages/django/core/handlers/base.py", line 249, in _legacy_get_response
    response = self._get_response(request)
  File "/usr/local/lib/python3.6/site-packages/django/core/handlers/base.py", line 187, in _get_response
    response = self.process_exception_by_middleware(e, request)
  File "/usr/local/lib/python3.6/site-packages/django/core/handlers/base.py", line 185, in _get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
  File "/usr/local/lib/python3.6/site-packages/django/views/decorators/csrf.py", line 58, in wrapped_view
    return view_func(*args, **kwargs)
  File "/usr/local/lib/python3.6/site-packages/django/views/decorators/http.py", line 40, in inner
    return func(request, *args, **kwargs)
  File "/home/docker/sal/sal/decorators.py", line 166, in wrap
    return function(request, *args, **kwargs)
  File "/home/docker/sal/server/non_ui_views.py", line 354, in checkin
    process_managed_items(machine, report_data, data.get('uuid'), now, datelimit)
  File "/home/docker/sal/server/non_ui_views.py", line 515, in process_managed_items
    model.objects.bulk_create(updates_to_save)
  File "/usr/local/lib/python3.6/site-packages/django/db/models/manager.py", line 85, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
  File "/usr/local/lib/python3.6/site-packages/django/db/models/query.py", line 452, in bulk_create
    ids = self._batched_insert(objs_without_pk, fields, batch_size)
  File "/usr/local/lib/python3.6/site-packages/django/db/models/query.py", line 1060, in _batched_insert
    inserted_id = self._insert(item, fields=fields, using=self.db, return_id=True)
  File "/usr/local/lib/python3.6/site-packages/django/db/models/query.py", line 1043, in _insert
    return query.get_compiler(using=using).execute_sql(return_id)
  File "/usr/local/lib/python3.6/site-packages/django/db/models/sql/compiler.py", line 1054, in execute_sql
    cursor.execute(sql, params)
  File "/usr/local/lib/python3.6/site-packages/django/db/backends/utils.py", line 79, in execute
    return super(CursorDebugWrapper, self).execute(sql, params)
  File "/usr/local/lib/python3.6/site-packages/django/db/backends/utils.py", line 64, in execute
    return self.cursor.execute(sql, params)
  File "/usr/local/lib/python3.6/site-packages/django/db/utils.py", line 94, in __exit__
    six.reraise(dj_exc_type, dj_exc_value, traceback)
  File "/usr/local/lib/python3.6/site-packages/django/utils/six.py", line 685, in reraise
    raise value.with_traceback(tb)
  File "/usr/local/lib/python3.6/site-packages/django/db/backends/utils.py", line 64, in execute
    return self.cursor.execute(sql, params)
django.db.utils.IntegrityError: duplicate key value violates unique constraint "server_updatehistoryite_update_history_id_78bcc0ce2c3b29f0_uniq"
DETAIL:  Key (update_history_id, recorded, status)=(649395, 2018-11-12 19:56:35+00, install) already exists.

ERROR:django.server:"POST /checkin/ HTTP/1.0" 500 270703

Changed files:
server/non_ui_views.py

diff --git a/server/non_ui_views.py b/server/non_ui_views.py
index 6288400..9751e35 100644
--- a/server/non_ui_views.py
+++ b/server/non_ui_views.py
@@ -476,6 +476,7 @@ def process_managed_items(machine, report_data, uuid, now, datelimit):
     # as we see them.
     # TODO: Process on the client side to avoid this.
     seen_updates = set()
+    start_time = dateutil.parser.parse(report_data['StartTime'])
     for item in report_data.get('ManagedInstalls', []):
         kwargs = {'update': item['name'], 'machine': machine}
         kwargs['display_name'] = item.get('display_name', item['name'])
@@ -495,18 +496,19 @@ def process_managed_items(machine, report_data, uuid, now, datelimit):
         items_to_create[InstalledUpdate].append(InstalledUpdate(**kwargs))
 
         # Change some kwarg names and prepare for the UpdateHIstory models.
-        kwargs['name'] = kwargs.pop('update')
-        kwargs.pop('display_name')
-        kwargs.pop('installed')
-        kwargs['version'] = kwargs.pop('update_version')
-        kwargs['recorded'] = dateutil.parser.parse(str(item['time'])) if 'time' in item else now
-        kwargs['uuid'] = uuid
-        update_history_item, update_history = process_update_history_item(
-            update_type='third_party', status='pending', **kwargs)
+        installed = kwargs.pop('installed')
+        if not installed:
+            kwargs['name'] = kwargs.pop('update')
+            kwargs.pop('display_name')
+            kwargs['version'] = kwargs.pop('update_version')
+            kwargs['recorded'] = start_time
+            kwargs['uuid'] = uuid
+            update_history_item, update_history = process_update_history_item(
+                update_type='third_party', status='pending', **kwargs)
 
-        if update_history_item is not None:
-            items_to_create[UpdateHistoryItem].append(update_history_item)
-            excluded_item_histories.add(update_history.pk)
+            if update_history_item is not None:
+                items_to_create[UpdateHistoryItem].append(update_history_item)
+                excluded_item_histories.add(update_history.pk)
 
     # Process pending Apple updates
     for item in report_data.get('AppleUpdates', []):
@@ -516,11 +518,11 @@ def process_managed_items(machine, report_data, uuid, now, datelimit):
 
         items_to_create[PendingAppleUpdate].append(PendingAppleUpdate(**kwargs))
 
-        # Change some kwarg names and prepare for the UpdateHIstory models.
+        # Change some kwarg names and prepare for the UpdateHistory models.
         kwargs['name'] = kwargs.pop('update')
         kwargs.pop('display_name')
         kwargs['version'] = kwargs.pop('update_version')
-        kwargs['recorded'] = dateutil.parser.parse(str(item['time'])) if 'time' in item else now
+        kwargs['recorded'] = start_time
         kwargs['uuid'] = uuid
         update_history_item, update_history = process_update_history_item(
             update_type='apple', status='pending', **kwargs)
@@ -536,7 +538,7 @@ def process_managed_items(machine, report_data, uuid, now, datelimit):
             kwargs['update_type'] = 'apple' if item.get('applesus') else 'third_party'
             kwargs['version'] = item.get('version', '0')
             kwargs['status'] = 'error' if item.get('status') != 0 else result_type
-            kwargs['recorded'] = dateutil.parser.parse(str(item['time'])) if 'time' in item else now
+            kwargs['recorded'] = pytz.timezone('UTC').localize(item['time'])
 
             update_history_item, update_history = process_update_history_item(
                 uuid=uuid, **kwargs)
@@ -580,7 +582,7 @@ def process_update_history_item(machine, update_type, name, version, recorded, u
     # Only create a history item if there are none or
     # if the last one is not the same status.
     items_set = update_history.updatehistoryitem_set.order_by('recorded')
-    if not items_set.exists() or items_set.last().status != status:
+    if not items_set.exists() or needs_history_item_creation(items_set, status, recorded):
         update_history_item = UpdateHistoryItem(
             update_history=update_history, status=status, recorded=recorded, uuid=uuid)
     else:
@@ -589,6 +591,10 @@ def process_update_history_item(machine, update_type, name, version, recorded, u
     return (update_history_item, update_history)
 
 
+def needs_history_item_creation(items_set, status, recorded):
+    return items_set.last().status != status and items_set.last().recorded < recorded
+
+
 def process_facts(machine, report_data, datelimit):
     # TODO: May need to come through and do get_or_create on machine, name, updating data, and
     # deleting now missing facts and conditions for non-postgres.