From 5c22fa25391723819b8e74b9fb5ce44f77a4c6d6 Mon Sep 17 00:00:00 2001
From: Ben McIlwain <mcilwain@google.com>
Date: Wed, 25 May 2022 17:27:21 -0400
Subject: [PATCH] Slightly improve performance of
 ExpandRecurringBillingEventsAction (#1642)

* Slightly improve performance of ExpandRecurringBillingEventsAction

We don't need to log every single no-op batch of 50 Recurrences that are
processed (considering we have 1.5M total in our system), and we also don't need
to process Recurrences that already ended prior to the Cursor time (this gets us
down to 420k from 1.5M).
---
 .../ExpandRecurringBillingEventsAction.java   | 25 +++++++++++++++----
 1 file changed, 20 insertions(+), 5 deletions(-)

diff --git a/core/src/main/java/google/registry/batch/ExpandRecurringBillingEventsAction.java b/core/src/main/java/google/registry/batch/ExpandRecurringBillingEventsAction.java
index 863b57231..27efd9a0b 100644
--- a/core/src/main/java/google/registry/batch/ExpandRecurringBillingEventsAction.java
+++ b/core/src/main/java/google/registry/batch/ExpandRecurringBillingEventsAction.java
@@ -67,6 +67,7 @@ import google.registry.util.Clock;
 import java.util.List;
 import java.util.Optional;
 import java.util.Set;
+import java.util.concurrent.TimeUnit;
 import javax.inject.Inject;
 import org.joda.money.Money;
 import org.joda.time.DateTime;
@@ -155,10 +156,12 @@ public class ExpandRecurringBillingEventsAction implements Runnable {
                                     + "WHERE eventTime <= :executeTime "
                                     + "AND eventTime < recurrenceEndTime "
                                     + "AND id > :maxProcessedRecurrenceId "
+                                    + "AND recurrenceEndTime > :cursorTime "
                                     + "ORDER BY id ASC",
                                 Recurring.class)
                             .setParameter("executeTime", executeTime)
                             .setParameter("maxProcessedRecurrenceId", prevMaxProcessedRecurrenceId)
+                            .setParameter("cursorTime", cursorTime)
                             .setMaxResults(batchSize)
                             .getResultList();
                     for (Recurring recurring : recurrings) {
@@ -191,15 +194,27 @@ public class ExpandRecurringBillingEventsAction implements Runnable {
                   });
       totalBillingEventsSaved += sqlBatchResults.batchBillingEventsSaved();
       maxProcessedRecurrenceId = sqlBatchResults.maxProcessedRecurrenceId();
-      logger.atInfo().log(
-          "Saved %d billing events in batch with max recurrence id %d.",
-          sqlBatchResults.batchBillingEventsSaved(), maxProcessedRecurrenceId);
+      if (sqlBatchResults.batchBillingEventsSaved() > 0) {
+        logger.atInfo().log(
+            "Saved %d billing events in batch (%d total) with max recurrence id %d.",
+            sqlBatchResults.batchBillingEventsSaved(),
+            totalBillingEventsSaved,
+            maxProcessedRecurrenceId);
+      } else {
+        // If we're churning through a lot of no-op recurrences that don't need expanding (yet?),
+        // then only log one no-op every so often as a good balance between letting the user track
+        // that the action is still running while also not spamming the logs incessantly.
+        logger.atInfo().atMostEvery(3, TimeUnit.MINUTES).log(
+            "Processed up to max recurrence id %d (no billing events saved recently).",
+            maxProcessedRecurrenceId);
+      }
     } while (sqlBatchResults.shouldContinue());
 
     if (!isDryRun) {
-      logger.atInfo().log("Saved OneTime billing events.", totalBillingEventsSaved);
+      logger.atInfo().log("Saved %d total OneTime billing events.", totalBillingEventsSaved);
     } else {
-      logger.atInfo().log("Generated OneTime billing events (dry run).", totalBillingEventsSaved);
+      logger.atInfo().log(
+          "Generated %d total OneTime billing events (dry run).", totalBillingEventsSaved);
     }
     logger.atInfo().log(
         "Recurring event expansion %s complete for billing event range [%s, %s).",