diff --git a/java/google/registry/dns/DnsConstants.java b/java/google/registry/dns/DnsConstants.java index ce0542582..37d1ec377 100644 --- a/java/google/registry/dns/DnsConstants.java +++ b/java/google/registry/dns/DnsConstants.java @@ -30,6 +30,9 @@ public class DnsConstants { /** The parameter to use for storing the target name (domain or host name) with the task. */ public static final String DNS_TARGET_NAME_PARAM = "Target-Name"; - /** The possible values of the {@code DNS_TARGET_NAME_PARAM} parameter. */ + /** The parameter to use for storing the creation time with the task. */ + public static final String DNS_TARGET_CREATE_TIME_PARAM = "Create-Time"; + + /** The possible values of the {@code DNS_TARGET_TYPE_PARAM} parameter. */ public enum TargetType { DOMAIN, HOST, ZONE } } diff --git a/java/google/registry/dns/DnsMetrics.java b/java/google/registry/dns/DnsMetrics.java index f8e950c73..b3564bebb 100644 --- a/java/google/registry/dns/DnsMetrics.java +++ b/java/google/registry/dns/DnsMetrics.java @@ -40,6 +40,9 @@ public class DnsMetrics { /** Disposition of writer.commit(). */ public enum CommitStatus { SUCCESS, FAILURE } + /** Disposition of the publish action. */ + public enum ActionStatus { SUCCESS, COMMIT_FAILURE, LOCK_FAILURE, BAD_WRITER } + private static final ImmutableSet LABEL_DESCRIPTORS_FOR_PUBLISH_REQUESTS = ImmutableSet.of( LabelDescriptor.create("tld", "TLD"), @@ -52,10 +55,16 @@ public class DnsMetrics { LabelDescriptor.create("status", "Whether writer.commit() succeeded or failed."), LabelDescriptor.create("dnsWriter", "The DnsWriter used.")); - // Finer-grained fitter than the DEFAULT_FITTER, allows values between 1. and 2^20, which gives - // over 15 minutes. + private static final ImmutableSet LABEL_DESCRIPTORS_FOR_LATENCY = + ImmutableSet.of( + LabelDescriptor.create("tld", "TLD"), + LabelDescriptor.create("status", "Whether the publish succeeded, or why it failed."), + LabelDescriptor.create("dnsWriter", "The DnsWriter used.")); + + // Finer-grained fitter than the DEFAULT_FITTER, allows values between 100 ms and just over 29 + // hours. private static final DistributionFitter EXPONENTIAL_FITTER = - ExponentialFitter.create(20, 2.0, 1.0); + ExponentialFitter.create(20, 2.0, 100.0); // Fibonacci fitter more suitible for integer-type values. Allows values between 0 and 10946, // which is the 21th Fibonacci number. @@ -156,6 +165,24 @@ public class DnsMetrics { LABEL_DESCRIPTORS_FOR_COMMIT, FIBONACCI_FITTER); + private static final EventMetric updateRequestLatency = + MetricRegistryImpl.getDefault() + .newEventMetric( + "/dns/update_latency", + "Time elapsed since refresh request was created until it was published", + "milliseconds", + LABEL_DESCRIPTORS_FOR_LATENCY, + EXPONENTIAL_FITTER); + + private static final EventMetric publishQueueDelay = + MetricRegistryImpl.getDefault() + .newEventMetric( + "/dns/publish_queue_delay", + "Time elapsed since the publishDnsUpdates action was created until it was executed", + "milliseconds", + LABEL_DESCRIPTORS_FOR_LATENCY, + EXPONENTIAL_FITTER); + @Inject RegistryEnvironment registryEnvironment; @Inject @Parameter(PARAM_TLD) String tld; @@ -225,4 +252,15 @@ public class DnsMetrics { domainsCommittedCount.incrementBy(numberOfDomains, tld, status.name(), dnsWriter); hostsCommittedCount.incrementBy(numberOfHosts, tld, status.name(), dnsWriter); } + + void recordActionResult( + String dnsWriter, + ActionStatus status, + int numberOfItems, + Duration timeSinceUpdateRequest, + Duration timeSinceActionEnqueued) { + updateRequestLatency.record( + timeSinceUpdateRequest.getMillis(), numberOfItems, tld, status.name(), dnsWriter); + publishQueueDelay.record(timeSinceActionEnqueued.getMillis(), tld, status.name(), dnsWriter); + } } diff --git a/java/google/registry/dns/DnsModule.java b/java/google/registry/dns/DnsModule.java index 5cebb11fe..4bea4e665 100644 --- a/java/google/registry/dns/DnsModule.java +++ b/java/google/registry/dns/DnsModule.java @@ -19,7 +19,10 @@ import static google.registry.dns.DnsConstants.DNS_PULL_QUEUE_NAME; import static google.registry.dns.PublishDnsUpdatesAction.PARAM_DNS_WRITER; import static google.registry.dns.PublishDnsUpdatesAction.PARAM_DOMAINS; import static google.registry.dns.PublishDnsUpdatesAction.PARAM_HOSTS; +import static google.registry.dns.PublishDnsUpdatesAction.PARAM_PUBLISH_TASK_ENQUEUED; +import static google.registry.dns.PublishDnsUpdatesAction.PARAM_REFRESH_REQUEST_CREATED; import static google.registry.request.RequestParameters.extractEnumParameter; +import static google.registry.request.RequestParameters.extractOptionalParameter; import static google.registry.request.RequestParameters.extractRequiredParameter; import static google.registry.request.RequestParameters.extractSetOfParameters; @@ -32,9 +35,11 @@ import google.registry.dns.DnsConstants.TargetType; import google.registry.dns.writer.DnsWriterZone; import google.registry.request.Parameter; import google.registry.request.RequestParameters; +import java.util.Optional; import java.util.Set; import javax.inject.Named; import javax.servlet.http.HttpServletRequest; +import org.joda.time.DateTime; /** Dagger module for the dns package. */ @Module @@ -56,6 +61,20 @@ public abstract class DnsModule { return QueueFactory.getQueue(DNS_PUBLISH_PUSH_QUEUE_NAME); } + @Provides + @Parameter(PARAM_PUBLISH_TASK_ENQUEUED) + // TODO(b/73343464): make the param required once the transition has finished + static Optional provideCreateTime(HttpServletRequest req) { + return extractOptionalParameter(req, PARAM_PUBLISH_TASK_ENQUEUED).map(DateTime::parse); + } + + @Provides + @Parameter(PARAM_REFRESH_REQUEST_CREATED) + // TODO(b/73343464): make the param required once the transition has finished + static Optional provideItemsCreateTime(HttpServletRequest req) { + return extractOptionalParameter(req, PARAM_REFRESH_REQUEST_CREATED).map(DateTime::parse); + } + @Provides @Parameter(PARAM_DNS_WRITER) static String provideDnsWriter(HttpServletRequest req) { diff --git a/java/google/registry/dns/DnsQueue.java b/java/google/registry/dns/DnsQueue.java index d2d6b09d3..1a50f5e9f 100644 --- a/java/google/registry/dns/DnsQueue.java +++ b/java/google/registry/dns/DnsQueue.java @@ -17,6 +17,7 @@ package google.registry.dns; import static com.google.appengine.api.taskqueue.QueueFactory.getQueue; import static com.google.common.base.Preconditions.checkArgument; import static google.registry.dns.DnsConstants.DNS_PULL_QUEUE_NAME; +import static google.registry.dns.DnsConstants.DNS_TARGET_CREATE_TIME_PARAM; import static google.registry.dns.DnsConstants.DNS_TARGET_NAME_PARAM; import static google.registry.dns.DnsConstants.DNS_TARGET_TYPE_PARAM; import static google.registry.model.registry.Registries.assertTldExists; @@ -37,8 +38,10 @@ import com.google.common.net.InternetDomainName; import com.google.common.util.concurrent.RateLimiter; import google.registry.dns.DnsConstants.TargetType; import google.registry.model.registry.Registries; +import google.registry.util.Clock; import google.registry.util.FormattingLogger; import google.registry.util.NonFinalForTesting; +import google.registry.util.SystemClock; import java.util.List; import java.util.Optional; import java.util.logging.Level; @@ -66,6 +69,8 @@ public class DnsQueue { private final Queue queue; + final Clock clock; + // Queue.leaseTasks is limited to 10 requests per second as per // https://cloud.google.com/appengine/docs/standard/java/javadoc/com/google/appengine/api/taskqueue/Queue.html // "If you generate more than 10 LeaseTasks requests per second, only the first 10 requests will @@ -73,8 +78,9 @@ public class DnsQueue { private static final RateLimiter rateLimiter = RateLimiter.create(9); @Inject - public DnsQueue(@Named(DNS_PULL_QUEUE_NAME) Queue queue) { + public DnsQueue(@Named(DNS_PULL_QUEUE_NAME) Queue queue, Clock clock) { this.queue = queue; + this.clock = clock; } /** @@ -85,7 +91,12 @@ public class DnsQueue { * reducer classes in mapreduces that need to be Serializable. */ public static DnsQueue create() { - return new DnsQueue(getQueue(DNS_PULL_QUEUE_NAME)); + return new DnsQueue(getQueue(DNS_PULL_QUEUE_NAME), new SystemClock()); + } + + @VisibleForTesting + public static DnsQueue createForTesting(Clock clock) { + return new DnsQueue(getQueue(DNS_PULL_QUEUE_NAME), clock); } @NonFinalForTesting @@ -99,12 +110,13 @@ public class DnsQueue { logger.infofmt( "Adding task type=%s, target=%s, tld=%s to pull queue %s (%d tasks currently on queue)", targetType, targetName, tld, DNS_PULL_QUEUE_NAME, queue.fetchStatistics().getNumTasks()); - return queue.add(TaskOptions.Builder - .withDefaults() - .method(Method.PULL) - .param(DNS_TARGET_TYPE_PARAM, targetType.toString()) - .param(DNS_TARGET_NAME_PARAM, targetName) - .param(PARAM_TLD, tld)); + return queue.add( + TaskOptions.Builder.withDefaults() + .method(Method.PULL) + .param(DNS_TARGET_TYPE_PARAM, targetType.toString()) + .param(DNS_TARGET_NAME_PARAM, targetName) + .param(DNS_TARGET_CREATE_TIME_PARAM, clock.nowUtc().toString()) + .param(PARAM_TLD, tld)); } /** diff --git a/java/google/registry/dns/PublishDnsUpdatesAction.java b/java/google/registry/dns/PublishDnsUpdatesAction.java index 52f66bfb6..4fc0bf497 100644 --- a/java/google/registry/dns/PublishDnsUpdatesAction.java +++ b/java/google/registry/dns/PublishDnsUpdatesAction.java @@ -20,6 +20,7 @@ import static google.registry.util.CollectionUtils.nullToEmpty; import com.google.common.net.InternetDomainName; import google.registry.config.RegistryConfig.Config; +import google.registry.dns.DnsMetrics.ActionStatus; import google.registry.dns.DnsMetrics.CommitStatus; import google.registry.dns.DnsMetrics.PublishStatus; import google.registry.dns.writer.DnsWriter; @@ -32,6 +33,7 @@ import google.registry.request.lock.LockHandler; import google.registry.util.Clock; import google.registry.util.DomainNameUtils; import google.registry.util.FormattingLogger; +import java.util.Optional; import java.util.Set; import java.util.concurrent.Callable; import javax.inject.Inject; @@ -51,6 +53,8 @@ public final class PublishDnsUpdatesAction implements Runnable, Callable { public static final String PARAM_DNS_WRITER = "dnsWriter"; public static final String PARAM_DOMAINS = "domains"; public static final String PARAM_HOSTS = "hosts"; + public static final String PARAM_PUBLISH_TASK_ENQUEUED = "enqueued"; + public static final String PARAM_REFRESH_REQUEST_CREATED = "itemsCreated"; public static final String LOCK_NAME = "DNS updates"; private static final FormattingLogger logger = FormattingLogger.getLoggerForCallerClass(); @@ -69,6 +73,10 @@ public final class PublishDnsUpdatesAction implements Runnable, Callable { * out (and not necessarily currently). */ @Inject @Parameter(PARAM_DNS_WRITER) String dnsWriter; + // TODO(b/73343464): make not-optional once transition has ended + @Inject @Parameter(PARAM_PUBLISH_TASK_ENQUEUED) Optional enqueuedTime; + // TODO(b/73343464): make not-optional once transition has ended + @Inject @Parameter(PARAM_REFRESH_REQUEST_CREATED) Optional itemsCreateTime; @Inject @Parameter(PARAM_DOMAINS) Set domains; @Inject @Parameter(PARAM_HOSTS) Set hosts; @@ -77,6 +85,26 @@ public final class PublishDnsUpdatesAction implements Runnable, Callable { @Inject Clock clock; @Inject PublishDnsUpdatesAction() {} + private void recordActionResult(ActionStatus status) { + DateTime now = clock.nowUtc(); + + dnsMetrics.recordActionResult( + dnsWriter, + status, + nullToEmpty(domains).size() + nullToEmpty(hosts).size(), + new Duration(itemsCreateTime.orElse(now), now), + new Duration(enqueuedTime.orElse(now), now)); + logger.infofmt( + "publishDnsWriter latency statistics: TLD: %s, dnsWriter: %s, actionStatus: %s, " + + "numItems: %s, timeSinceCreation: %s, timeInQueue: %s", + tld, + dnsWriter, + status, + nullToEmpty(domains).size() + nullToEmpty(hosts).size(), + new Duration(itemsCreateTime.orElse(now), now), + new Duration(enqueuedTime.orElse(now), now)); + } + /** Runs the task. */ @Override public void run() { @@ -85,6 +113,7 @@ public final class PublishDnsUpdatesAction implements Runnable, Callable { // in the update task being dequeued and dropped. A message will already have been logged // to indicate the problem. if (!lockHandler.executeWithLocks(this, tld, timeout, LOCK_NAME)) { + recordActionResult(ActionStatus.LOCK_FAILURE); throw new ServiceUnavailableException("Lock failure"); } } @@ -116,6 +145,7 @@ public final class PublishDnsUpdatesAction implements Runnable, Callable { logger.warningfmt( "Couldn't get writer %s for TLD %s, pushing domains back to the queue for retry", dnsWriter, tld); + recordActionResult(ActionStatus.BAD_WRITER); requeueBatch(); return; } @@ -155,11 +185,14 @@ public final class PublishDnsUpdatesAction implements Runnable, Callable { // If we got here it means we managed to stage the entire batch without any errors. // Next we will commit the batch. CommitStatus commitStatus = CommitStatus.FAILURE; + ActionStatus actionStatus = ActionStatus.COMMIT_FAILURE; try { writer.commit(); // No error was thrown commitStatus = CommitStatus.SUCCESS; + actionStatus = ActionStatus.SUCCESS; } finally { + recordActionResult(actionStatus); Duration duration = new Duration(timeAtStart, clock.nowUtc()); dnsMetrics.recordCommit( dnsWriter, @@ -168,9 +201,10 @@ public final class PublishDnsUpdatesAction implements Runnable, Callable { domainsPublished, hostsPublished); logger.infofmt( - "writer.commit() statistics:: TLD: %s, commitStatus: %s, duration: %s, " + "writer.commit() statistics: TLD: %s, dnsWriter: %s, commitStatus: %s, duration: %s, " + "domainsPublished: %d, domainsRejected: %d, hostsPublished: %d, hostsRejected: %d", tld, + dnsWriter, commitStatus, duration, domainsPublished, diff --git a/java/google/registry/dns/ReadDnsQueueAction.java b/java/google/registry/dns/ReadDnsQueueAction.java index 66c5f688c..d806fdfa3 100644 --- a/java/google/registry/dns/ReadDnsQueueAction.java +++ b/java/google/registry/dns/ReadDnsQueueAction.java @@ -17,6 +17,7 @@ package google.registry.dns; import static com.google.appengine.api.taskqueue.TaskOptions.Builder.withUrl; import static com.google.common.collect.Sets.difference; import static google.registry.dns.DnsConstants.DNS_PUBLISH_PUSH_QUEUE_NAME; +import static google.registry.dns.DnsConstants.DNS_TARGET_CREATE_TIME_PARAM; import static google.registry.dns.DnsConstants.DNS_TARGET_NAME_PARAM; import static google.registry.dns.DnsConstants.DNS_TARGET_TYPE_PARAM; import static java.util.concurrent.TimeUnit.SECONDS; @@ -44,6 +45,7 @@ import google.registry.util.FormattingLogger; import google.registry.util.TaskEnqueuer; import java.io.UnsupportedEncodingException; import java.util.Collection; +import java.util.Comparator; import java.util.List; import java.util.Map; import java.util.Optional; @@ -99,19 +101,22 @@ public final class ReadDnsQueueAction implements Runnable { /** Container for items we pull out of the DNS pull queue and process for fanout. */ @AutoValue abstract static class RefreshItem implements Comparable { - static RefreshItem create(TargetType type, String name) { - return new AutoValue_ReadDnsQueueAction_RefreshItem(type, name); + static RefreshItem create(TargetType type, String name, DateTime creationTime) { + return new AutoValue_ReadDnsQueueAction_RefreshItem(type, name, creationTime); } abstract TargetType type(); abstract String name(); + abstract DateTime creationTime(); + @Override public int compareTo(RefreshItem other) { return ComparisonChain.start() .compare(this.type(), other.type()) .compare(this.name(), other.name()) + .compare(this.creationTime(), other.creationTime()) .result(); } } @@ -207,7 +212,7 @@ public final class ReadDnsQueueAction implements Runnable { * tasks for paused TLDs or tasks for TLDs not part of {@link Registries#getTlds()}. */ private void dispatchTasks(ImmutableSet tasks, ImmutableSet tlds) { - ClassifiedTasks classifiedTasks = classifyTasks(tasks, tlds); + ClassifiedTasks classifiedTasks = classifyTasks(tasks, tlds, clock.nowUtc()); if (!classifiedTasks.pausedTlds().isEmpty()) { logger.infofmt("The dns-pull queue is paused for TLDs: %s.", classifiedTasks.pausedTlds()); } @@ -244,7 +249,7 @@ public final class ReadDnsQueueAction implements Runnable { * taken on them) or in no category (if no action is to be taken on them) */ private static ClassifiedTasks classifyTasks( - ImmutableSet tasks, ImmutableSet tlds) { + ImmutableSet tasks, ImmutableSet tlds, DateTime now) { ClassifiedTasks.Builder classifiedTasksBuilder = ClassifiedTasks.builder(); @@ -252,6 +257,14 @@ public final class ReadDnsQueueAction implements Runnable { for (TaskHandle task : tasks) { try { Map params = ImmutableMap.copyOf(task.extractParams()); + // We allow 'null' create-time for the transition period - and during that time we set the + // create-time to "now". + // + // TODO(b/73343464):remove support for null create-time once transition is over. + DateTime creationTime = + Optional.ofNullable(params.get(DNS_TARGET_CREATE_TIME_PARAM)) + .map(DateTime::parse) + .orElse(now); String tld = params.get(RequestParameters.PARAM_TLD); if (tld == null) { logger.severefmt("Discarding invalid DNS refresh request %s; no TLD specified.", task); @@ -270,7 +283,7 @@ public final class ReadDnsQueueAction implements Runnable { case HOST: classifiedTasksBuilder .refreshItemsByTldBuilder() - .put(tld, RefreshItem.create(type, name)); + .put(tld, RefreshItem.create(type, name, creationTime)); break; default: logger.severefmt("Discarding DNS refresh request %s of type %s.", task, typeString); @@ -292,13 +305,23 @@ public final class ReadDnsQueueAction implements Runnable { String tld = tldRefreshItemsEntry.getKey(); for (List chunk : Iterables.partition(tldRefreshItemsEntry.getValue(), tldUpdateBatchSize)) { + DateTime earliestCreateTime = + chunk.stream().map(RefreshItem::creationTime).min(Comparator.naturalOrder()).get(); for (String dnsWriter : Registry.get(tld).getDnsWriters()) { - TaskOptions options = withUrl(PublishDnsUpdatesAction.PATH) - .countdownMillis(jitterSeconds.isPresent() - ? random.nextInt((int) SECONDS.toMillis(jitterSeconds.get())) - : 0) - .param(RequestParameters.PARAM_TLD, tld) - .param(PublishDnsUpdatesAction.PARAM_DNS_WRITER, dnsWriter); + TaskOptions options = + withUrl(PublishDnsUpdatesAction.PATH) + .countdownMillis( + jitterSeconds.isPresent() + ? random.nextInt((int) SECONDS.toMillis(jitterSeconds.get())) + : 0) + .param(RequestParameters.PARAM_TLD, tld) + .param(PublishDnsUpdatesAction.PARAM_DNS_WRITER, dnsWriter) + .param( + PublishDnsUpdatesAction.PARAM_PUBLISH_TASK_ENQUEUED, + clock.nowUtc().toString()) + .param( + PublishDnsUpdatesAction.PARAM_REFRESH_REQUEST_CREATED, + earliestCreateTime.toString()); for (RefreshItem refreshItem : chunk) { options.param( (refreshItem.type() == TargetType.HOST) diff --git a/javatests/google/registry/dns/DnsQueueTest.java b/javatests/google/registry/dns/DnsQueueTest.java index 5829945ac..e6c278f2d 100644 --- a/javatests/google/registry/dns/DnsQueueTest.java +++ b/javatests/google/registry/dns/DnsQueueTest.java @@ -21,7 +21,9 @@ import static google.registry.testing.TaskQueueHelper.assertNoTasksEnqueued; import static google.registry.testing.TaskQueueHelper.assertTasksEnqueued; import google.registry.testing.AppEngineRule; +import google.registry.testing.FakeClock; import google.registry.testing.TaskQueueHelper.TaskMatcher; +import org.joda.time.DateTime; import org.junit.Before; import org.junit.Rule; import org.junit.Test; @@ -38,10 +40,11 @@ public class DnsQueueTest { .withTaskQueue() .build(); private DnsQueue dnsQueue; + private final FakeClock clock = new FakeClock(DateTime.parse("2010-01-01T10:00:00Z")); @Before public void init() { - dnsQueue = DnsQueue.create(); + dnsQueue = DnsQueue.createForTesting(clock); dnsQueue.leaseTasksBatchSize = 10; } @@ -54,6 +57,7 @@ public class DnsQueueTest { new TaskMatcher() .param("Target-Type", "HOST") .param("Target-Name", "octopus.tld") + .param("Create-Time", "2010-01-01T10:00:00.000Z") .param("tld", "tld")); } @@ -83,6 +87,7 @@ public class DnsQueueTest { new TaskMatcher() .param("Target-Type", "DOMAIN") .param("Target-Name", "octopus.tld") + .param("Create-Time", "2010-01-01T10:00:00.000Z") .param("tld", "tld")); } @@ -101,4 +106,3 @@ public class DnsQueueTest { assertThat(thrown).hasMessageThat().contains("TLD notatld does not exist"); } } - diff --git a/javatests/google/registry/dns/PublishDnsUpdatesActionTest.java b/javatests/google/registry/dns/PublishDnsUpdatesActionTest.java index f2e5a0f48..bc4f9b7a1 100644 --- a/javatests/google/registry/dns/PublishDnsUpdatesActionTest.java +++ b/javatests/google/registry/dns/PublishDnsUpdatesActionTest.java @@ -20,12 +20,14 @@ import static google.registry.testing.DatastoreHelper.persistActiveDomain; import static google.registry.testing.DatastoreHelper.persistActiveSubordinateHost; import static google.registry.testing.DatastoreHelper.persistResource; import static google.registry.testing.JUnitBackports.expectThrows; +import static org.mockito.Mockito.doThrow; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.verify; import static org.mockito.Mockito.verifyNoMoreInteractions; import com.google.common.collect.ImmutableMap; import com.google.common.collect.ImmutableSet; +import google.registry.dns.DnsMetrics.ActionStatus; import google.registry.dns.DnsMetrics.CommitStatus; import google.registry.dns.DnsMetrics.PublishStatus; import google.registry.dns.writer.DnsWriter; @@ -37,6 +39,7 @@ import google.registry.testing.AppEngineRule; import google.registry.testing.FakeClock; import google.registry.testing.FakeLockHandler; import google.registry.testing.InjectRule; +import java.util.Optional; import org.joda.time.DateTime; import org.joda.time.Duration; import org.junit.Before; @@ -87,6 +90,8 @@ public class PublishDnsUpdatesActionTest { action.tld = tld; action.hosts = ImmutableSet.of(); action.domains = ImmutableSet.of(); + action.itemsCreateTime = Optional.of(clock.nowUtc().minusHours(2)); + action.enqueuedTime = Optional.of(clock.nowUtc().minusHours(1)); action.dnsWriter = "correctWriter"; action.dnsWriterProxy = new DnsWriterProxy(ImmutableMap.of("correctWriter", dnsWriter)); action.dnsMetrics = dnsMetrics; @@ -111,6 +116,13 @@ public class PublishDnsUpdatesActionTest { verify(dnsMetrics).incrementPublishHostRequests(1, PublishStatus.ACCEPTED); verify(dnsMetrics).incrementPublishHostRequests(0, PublishStatus.REJECTED); verify(dnsMetrics).recordCommit("correctWriter", CommitStatus.SUCCESS, Duration.ZERO, 0, 1); + verify(dnsMetrics) + .recordActionResult( + "correctWriter", + ActionStatus.SUCCESS, + 1, + Duration.standardHours(2), + Duration.standardHours(1)); verifyNoMoreInteractions(dnsMetrics); verifyNoMoreInteractions(dnsQueue); @@ -131,6 +143,40 @@ public class PublishDnsUpdatesActionTest { verify(dnsMetrics).incrementPublishHostRequests(0, PublishStatus.ACCEPTED); verify(dnsMetrics).incrementPublishHostRequests(0, PublishStatus.REJECTED); verify(dnsMetrics).recordCommit("correctWriter", CommitStatus.SUCCESS, Duration.ZERO, 1, 0); + verify(dnsMetrics) + .recordActionResult( + "correctWriter", + ActionStatus.SUCCESS, + 1, + Duration.standardHours(2), + Duration.standardHours(1)); + verifyNoMoreInteractions(dnsMetrics); + + verifyNoMoreInteractions(dnsQueue); + } + + @Test + public void testPublish_commitFails() throws Exception { + action = createAction("xn--q9jyb4c"); + action.domains = ImmutableSet.of("example.xn--q9jyb4c", "example2.xn--q9jyb4c"); + action.hosts = + ImmutableSet.of( + "ns1.example.xn--q9jyb4c", "ns2.example.xn--q9jyb4c", "ns1.example2.xn--q9jyb4c"); + doThrow(new RuntimeException()).when(dnsWriter).commit(); + expectThrows(RuntimeException.class, action::run); + + verify(dnsMetrics).incrementPublishDomainRequests(2, PublishStatus.ACCEPTED); + verify(dnsMetrics).incrementPublishDomainRequests(0, PublishStatus.REJECTED); + verify(dnsMetrics).incrementPublishHostRequests(3, PublishStatus.ACCEPTED); + verify(dnsMetrics).incrementPublishHostRequests(0, PublishStatus.REJECTED); + verify(dnsMetrics).recordCommit("correctWriter", CommitStatus.FAILURE, Duration.ZERO, 2, 3); + verify(dnsMetrics) + .recordActionResult( + "correctWriter", + ActionStatus.COMMIT_FAILURE, + 5, + Duration.standardHours(2), + Duration.standardHours(1)); verifyNoMoreInteractions(dnsMetrics); verifyNoMoreInteractions(dnsQueue); @@ -157,6 +203,13 @@ public class PublishDnsUpdatesActionTest { verify(dnsMetrics).incrementPublishHostRequests(3, PublishStatus.ACCEPTED); verify(dnsMetrics).incrementPublishHostRequests(0, PublishStatus.REJECTED); verify(dnsMetrics).recordCommit("correctWriter", CommitStatus.SUCCESS, Duration.ZERO, 2, 3); + verify(dnsMetrics) + .recordActionResult( + "correctWriter", + ActionStatus.SUCCESS, + 5, + Duration.standardHours(2), + Duration.standardHours(1)); verifyNoMoreInteractions(dnsMetrics); verifyNoMoreInteractions(dnsQueue); @@ -177,6 +230,13 @@ public class PublishDnsUpdatesActionTest { verify(dnsMetrics).incrementPublishHostRequests(0, PublishStatus.ACCEPTED); verify(dnsMetrics).incrementPublishHostRequests(3, PublishStatus.REJECTED); verify(dnsMetrics).recordCommit("correctWriter", CommitStatus.SUCCESS, Duration.ZERO, 0, 0); + verify(dnsMetrics) + .recordActionResult( + "correctWriter", + ActionStatus.SUCCESS, + 5, + Duration.standardHours(2), + Duration.standardHours(1)); verifyNoMoreInteractions(dnsMetrics); verifyNoMoreInteractions(dnsQueue); @@ -184,24 +244,26 @@ public class PublishDnsUpdatesActionTest { @Test public void testLockIsntAvailable() throws Exception { + action = createAction("xn--q9jyb4c"); + action.domains = ImmutableSet.of("example.com", "example2.com"); + action.hosts = ImmutableSet.of("ns1.example.com", "ns2.example.com", "ns1.example2.com"); + action.lockHandler = new FakeLockHandler(false); ServiceUnavailableException thrown = - expectThrows( - ServiceUnavailableException.class, - () -> { - action = createAction("xn--q9jyb4c"); - action.domains = ImmutableSet.of("example.com", "example2.com"); - action.hosts = - ImmutableSet.of("ns1.example.com", "ns2.example.com", "ns1.example2.com"); - action.lockHandler = new FakeLockHandler(false); - action.run(); - - verifyNoMoreInteractions(dnsWriter); - - verifyNoMoreInteractions(dnsMetrics); - - verifyNoMoreInteractions(dnsQueue); - }); + expectThrows(ServiceUnavailableException.class, action::run); assertThat(thrown).hasMessageThat().contains("Lock failure"); + + verifyNoMoreInteractions(dnsWriter); + + verify(dnsMetrics) + .recordActionResult( + "correctWriter", + ActionStatus.LOCK_FAILURE, + 5, + Duration.standardHours(2), + Duration.standardHours(1)); + verifyNoMoreInteractions(dnsMetrics); + + verifyNoMoreInteractions(dnsQueue); } @Test @@ -214,6 +276,13 @@ public class PublishDnsUpdatesActionTest { verifyNoMoreInteractions(dnsWriter); + verify(dnsMetrics) + .recordActionResult( + "wrongWriter", + ActionStatus.BAD_WRITER, + 5, + Duration.standardHours(2), + Duration.standardHours(1)); verifyNoMoreInteractions(dnsMetrics); verify(dnsQueue).addDomainRefreshTask("example.com"); diff --git a/javatests/google/registry/dns/ReadDnsQueueActionTest.java b/javatests/google/registry/dns/ReadDnsQueueActionTest.java index 05a8062e0..bedd0c09c 100644 --- a/javatests/google/registry/dns/ReadDnsQueueActionTest.java +++ b/javatests/google/registry/dns/ReadDnsQueueActionTest.java @@ -21,6 +21,7 @@ import static com.google.common.truth.Truth.assertThat; import static com.google.common.truth.Truth8.assertThat; import static google.registry.dns.DnsConstants.DNS_PUBLISH_PUSH_QUEUE_NAME; import static google.registry.dns.DnsConstants.DNS_PULL_QUEUE_NAME; +import static google.registry.dns.DnsConstants.DNS_TARGET_CREATE_TIME_PARAM; import static google.registry.dns.DnsConstants.DNS_TARGET_NAME_PARAM; import static google.registry.dns.DnsConstants.DNS_TARGET_TYPE_PARAM; import static google.registry.request.RequestParameters.PARAM_TLD; @@ -52,7 +53,6 @@ import java.util.Map.Entry; import java.util.Optional; import java.util.stream.IntStream; import org.joda.time.DateTime; -import org.joda.time.DateTimeZone; import org.joda.time.Duration; import org.junit.Before; import org.junit.Rule; @@ -66,7 +66,7 @@ public class ReadDnsQueueActionTest { private static final int TEST_TLD_UPDATE_BATCH_SIZE = 100; private DnsQueue dnsQueue; - private FakeClock clock = new FakeClock(DateTime.now(DateTimeZone.UTC)); + private FakeClock clock = new FakeClock(DateTime.parse("3000-01-01TZ")); @Rule public final AppEngineRule appEngine = AppEngineRule.builder() @@ -88,7 +88,9 @@ public class ReadDnsQueueActionTest { @Before public void before() throws Exception { - clock.setTo(DateTime.now(DateTimeZone.UTC)); + // Because of b/73372999 - the FakeClock can't be in the past, or the TaskQueues stop working. + // To make sure it's never in the past, we set the date far-far into the future + clock.setTo(DateTime.parse("3000-01-01TZ")); createTlds("com", "net", "example"); persistResource( Registry.get("com").asBuilder().setDnsWriters(ImmutableSet.of("comWriter")).build()); @@ -100,7 +102,7 @@ public class ReadDnsQueueActionTest { .setTldType(TldType.TEST) .setDnsWriters(ImmutableSet.of("exampleWriter")) .build()); - dnsQueue = DnsQueue.create(); + dnsQueue = DnsQueue.createForTesting(clock); } private void run() throws Exception { @@ -113,7 +115,7 @@ public class ReadDnsQueueActionTest { action.taskEnqueuer = new TaskEnqueuer(new Retrier(null, 1)); action.jitterSeconds = Optional.empty(); // Advance the time a little, to ensure that leaseTasks() returns all tasks. - clock.setTo(DateTime.now(DateTimeZone.UTC).plusMillis(1)); + clock.advanceBy(Duration.standardHours(1)); action.run(); } @@ -134,6 +136,8 @@ public class ReadDnsQueueActionTest { private void assertTldsEnqueuedInPushQueue(ImmutableMultimap tldsToDnsWriters) throws Exception { + // By default, the publishDnsUpdates tasks will be enqueued one hour after the update items were + // created in the pull queue. This is because of the clock.advanceBy in run() assertTasksEnqueued( DNS_PUBLISH_PUSH_QUEUE_NAME, transform( @@ -143,6 +147,8 @@ public class ReadDnsQueueActionTest { .url(PublishDnsUpdatesAction.PATH) .param("tld", tldToDnsWriter.getKey()) .param("dnsWriter", tldToDnsWriter.getValue()) + .param("itemsCreated", "3000-01-01T00:00:00.000Z") + .param("enqueued", "3000-01-01T01:00:00.000Z") .header("content-type", "application/x-www-form-urlencoded"))); } @@ -208,6 +214,29 @@ public class ReadDnsQueueActionTest { assertTldsEnqueuedInPushQueue(ImmutableMultimap.of("com", "comWriter", "com", "otherWriter")); } + @Test + public void testSuccess_differentUpdateTimes_usesMinimum() throws Exception { + clock.setTo(DateTime.parse("3000-02-03TZ")); + dnsQueue.addDomainRefreshTask("domain1.com"); + clock.setTo(DateTime.parse("3000-02-04TZ")); + dnsQueue.addDomainRefreshTask("domain2.com"); + clock.setTo(DateTime.parse("3000-02-05TZ")); + dnsQueue.addDomainRefreshTask("domain3.com"); + run(); + assertNoTasksEnqueued(DNS_PULL_QUEUE_NAME); + assertThat(getQueuedParams(DNS_PUBLISH_PUSH_QUEUE_NAME)) + .containsExactly( + new ImmutableMultimap.Builder() + .put("enqueued", "3000-02-05T01:00:00.000Z") + .put("itemsCreated", "3000-02-03T00:00:00.000Z") + .put("tld", "com") + .put("dnsWriter", "comWriter") + .put("domains", "domain1.com") + .put("domains", "domain2.com") + .put("domains", "domain3.com") + .build()); + } + @Test public void testSuccess_oneTldPaused_returnedToQueue() throws Exception { persistResource(Registry.get("net").asBuilder().setDnsPaused(true).build()); @@ -248,6 +277,7 @@ public class ReadDnsQueueActionTest { .method(Method.PULL) .param(DNS_TARGET_TYPE_PARAM, TargetType.DOMAIN.toString()) .param(DNS_TARGET_NAME_PARAM, "domain.wrongtld") + .param(DNS_TARGET_CREATE_TIME_PARAM, "3000-01-01TZ") .param(PARAM_TLD, "net")); run(); assertNoTasksEnqueued(DNS_PULL_QUEUE_NAME);