feat(osf): ENG-11735 record download events for files and zips

Author: sh-andriy

osf/utils/download_telemetry.py

@@ -11,6 +11,10 @@
 # about where they actually are.
 UNSET_USER_TIMEZONE = 'Etc/UTC'
 
+# Identifiers worth having in the log line to track a failure back to one download.
+# Deliberately excludes the IP.
+LOGGED_CONTEXT_KEYS = ('download_type', 'resource_guid', 'file_id', 'user_guid')
+
 
 def never_breaks_downloads(fn):
     """Swallow and log anything this raises.
@@ -22,8 +26,20 @@ def never_breaks_downloads(fn):
     def wrapped(*args, **kwargs):
         try:
             return fn(*args, **kwargs)
-        except Exception:
-            logger.exception('Failed to record a download event')
+        except Exception as exc:
+            # exc_info carries the traceback; the rest names the failure and which
+            # download it was, so a report is actionable without reproducing it.
+            logger.exception(
+                'Failed to record a download event in %s: %s: %s [%s]',
+                fn.__name__,
+                type(exc).__name__,
+                exc,
+                ', '.join(
+                    f'{key}={kwargs[key]!r}'
+                    for key in LOGGED_CONTEXT_KEYS
+                    if kwargs.get(key)
+                ) or 'no context',
+            )
     return wrapped
 
 

tests/test_download_telemetry.py

@@ -1,3 +1,4 @@
+import logging
 import time
 
 import pytest
@@ -208,3 +209,30 @@ def explode(*args, **kwargs):
         record_download(download_type=DownloadEvent.FILE, resource_guid='abcde')
 
         assert not DownloadEvent.objects.exists()
+
+    def test_failure_is_logged_with_the_cause_and_the_download(self, monkeypatch, caplog):
+        """A report has to be actionable without reproducing it."""
+        def explode(*args, **kwargs):
+            raise ValueError('boom')
+
+        monkeypatch.setattr('osf.utils.download_telemetry.enqueue_postcommit_task', explode)
+
+        with caplog.at_level(logging.ERROR, logger='osf.utils.download_telemetry'):
+            record_download(
+                download_type=DownloadEvent.FILE,
+                resource_guid='abcde',
+                user_guid='zyxwv',
+                ip='198.51.100.7',
+            )
+
+        record = caplog.records[0]
+        message = record.getMessage()
+        assert 'ValueError' in message
+        assert 'boom' in message
+        assert 'record_download' in message
+        assert "resource_guid='abcde'" in message
+        assert "user_guid='zyxwv'" in message
+        # the IP is not debugging information
+        assert '198.51.100.7' not in message
+        # the traceback is still attached
+        assert record.exc_info is not None