From 5884be8300e03e276113738f80d21f6ab55c42b5 Mon Sep 17 00:00:00 2001
From: Ryan Barrett <git@ryanb.org>
Date: Tue, 17 Sep 2024 17:51:20 -0700
Subject: [PATCH] send task: log delay from when Object was created

for #1308, 85b9643cda854095a9c5d6c2063c951f8055a8c1
---
 protocol.py            | 5 ++++-
 tests/test_protocol.py | 2 +-
 2 files changed, 5 insertions(+), 2 deletions(-)

diff --git a/protocol.py b/protocol.py
index 9213b1f2..3d919e2c 100644
--- a/protocol.py
+++ b/protocol.py
@@ -1709,7 +1709,10 @@ def send_task():
                 if form.get('orig_obj') else None)
 
     # send
-    logger.info(f'Sending {obj.source_protocol} {obj.type} {obj.key.id()} to {protocol} {url}')
+    delay = ''
+    if request.headers.get('X-AppEngine-TaskRetryCount') == '0' and obj.created:
+        delay = f'({(util.now().replace(tzinfo=None) - obj.created).total_seconds()} s behind)'
+    logger.info(f'Sending {obj.source_protocol} {obj.type} {obj.key.id()} to {protocol} {url} {delay}')
     logger.debug(f'  AS1: {json_dumps(obj.as1, indent=2)}')
     sent = None
     try:
diff --git a/tests/test_protocol.py b/tests/test_protocol.py
index f7f948c1..34750809 100644
--- a/tests/test_protocol.py
+++ b/tests/test_protocol.py
@@ -3199,7 +3199,7 @@ def test_send_task_handler(self):
             'orig_obj': note.key.urlsafe(),
             'url': 'fake:shared:target',
             'user': self.user.key.urlsafe(),
-        })
+        }, headers={'X-AppEngine-TaskRetryCount': '0'})
         self.assertEqual(200, resp.status_code)
 
     def test_send_task_missing_url(self):