Improve logging of endorsements expirations

ts/groups.ts

@@ -3989,13 +3989,15 @@ async function updateGroupViaLogs({
   let cachedEndorsementsExpiration =
     await DataReader.getGroupSendCombinedEndorsementExpiration(groupId);
 
-  if (
+  if (cachedEndorsementsExpiration != null) {
-    cachedEndorsementsExpiration != null &&
+    const result = isValidGroupSendEndorsementsExpiration(
-    !isValidGroupSendEndorsementsExpiration(cachedEndorsementsExpiration * 1000)
+      cachedEndorsementsExpiration * 1000
-  ) {
-    log.info(
-      `updateGroupViaLogs/${logId}: Group had invalid endorsements expiration (${cachedEndorsementsExpiration}), fetching new endorsements`
     );
+    if (!result.valid) {
+      log.info(
+        `updateGroupViaLogs/${logId}: Endorsements are expired (${result.reason}), fetching new endorsements`
+      );
+    }
     cachedEndorsementsExpiration = null;
   }
 

ts/test-node/util/groupSendEndorsements_test.ts

@@ -0,0 +1,46 @@
+// Copyright 2024 Signal Messenger, LLC
+// SPDX-License-Identifier: AGPL-3.0-only
+
+import assert from 'node:assert/strict';
+import { isValidGroupSendEndorsementsExpiration } from '../../util/groupSendEndorsements';
+import { DAY, HOUR, SECOND } from '../../util/durations';
+
+describe('groupSendEndorsements', () => {
+  describe('isValidGroupSendEndorsementsExpiration', () => {
+    function validateDistance(distance: number) {
+      const expiration = Date.now() + distance;
+      return isValidGroupSendEndorsementsExpiration(expiration);
+    }
+
+    function checkValid(label: string, distance: number) {
+      it(label, () => {
+        const actual = validateDistance(distance);
+        assert.equal(actual.valid, true);
+        assert.equal(actual.reason, undefined);
+      });
+    }
+
+    function checkInvalid(label: string, distance: number, reason: RegExp) {
+      it(label, () => {
+        const actual = validateDistance(distance);
+        assert.equal(actual.valid, false);
+        assert.match(actual.reason, reason);
+      });
+    }
+
+    const TWO_HOURS = HOUR * 2;
+    const TWO_DAYS = DAY * 2;
+
+    checkInvalid('2d ago', -TWO_DAYS, /already expired/);
+    checkInvalid('2h ago', -TWO_HOURS, /already expired/);
+    checkInvalid('1s ago', -SECOND, /already expired/);
+    checkInvalid('now', 0, /already expired/);
+    checkInvalid('in 1s', SECOND, /expires soon/);
+    checkInvalid('in <2h', TWO_HOURS - SECOND, /expires soon/);
+    checkInvalid('in 2h', TWO_HOURS, /expires soon/);
+    checkValid('in >2h', TWO_HOURS + SECOND);
+    checkValid('in <2d', TWO_DAYS - SECOND);
+    checkInvalid('in 2d', TWO_DAYS, /expires too far in future/);
+    checkInvalid('in >2d', TWO_DAYS + SECOND, /expires too far in future/);
+  });
+});

ts/util/groupSendEndorsements.ts

@@ -129,13 +129,28 @@ function logServiceIds(list: Iterable<string>) {
   return `${items.slice(0, 4).join(', ')}, and ${items.length - 4} others`;
 }
 
+export type EndorsementsExpirationValidationResult =
+  | { valid: true; reason?: never }
+  | { valid: false; reason: string };
+
 export function isValidGroupSendEndorsementsExpiration(
   expiration: number
-): boolean {
+): EndorsementsExpirationValidationResult {
   const expSeconds = DurationInSeconds.fromMillis(expiration);
   const nowSeconds = DurationInSeconds.fromMillis(Date.now());
+  const info = `now: ${nowSeconds}, exp: ${expSeconds}`;
+  if (expSeconds <= nowSeconds) {
+    return { valid: false, reason: `already expired, ${info}` };
+  }
+  // negative = exp is past, positive = exp is future
   const distance = Math.trunc(expSeconds - nowSeconds);
-  return distance <= TWO_DAYS && distance > TWO_HOURS;
+  if (distance <= TWO_HOURS) {
+    return { valid: false, reason: `expires soon, ${info}` };
+  }
+  if (distance >= TWO_DAYS) {
+    return { valid: false, reason: `expires too far in future, ${info}` };
+  }
+  return { valid: true };
 }
 
 export class GroupSendEndorsementState {
@@ -162,12 +177,6 @@ export class GroupSendEndorsementState {
     }
   }
 
-  isSafeExpirationRange(): boolean {
-    return isValidGroupSendEndorsementsExpiration(
-      this.getExpiration().getTime()
-    );
-  }
-
   getExpiration(): Date {
     return new Date(this.#combinedEndorsement.expiration * 1000);
   }
@@ -366,13 +375,21 @@ export async function maybeCreateGroupSendEndorsementState(
     groupSecretParamsBase64
   );
 
-  if (
+  const result = isValidGroupSendEndorsementsExpiration(
-    groupSendEndorsementState != null &&
+    groupSendEndorsementState.getExpiration().getTime()
-    !groupSendEndorsementState.isSafeExpirationRange() &&
+  );
-    !alreadyRefreshedGroupState
+
-  ) {
+  if (!result.valid) {
+    if (alreadyRefreshedGroupState) {
+      onFailedToSendWithEndorsements(
+        new Error(
+          `${logId}: Endorsements are expired after refreshing group (${result.reason})`
+        )
+      );
+      return { state: null, didRefreshGroupState: false };
+    }
     log.info(
-      `${logId}: Endorsements close to expiration (${groupSendEndorsementState.getExpiration().getTime()}, ${Date.now()}), refreshing group`
+      `${logId}: Endorsements are expired (${result.reason}), refreshing group`
     );
     await maybeUpdateGroup({ conversation });
     return { state: null, didRefreshGroupState: true };