diff --git a/java/google/registry/util/RequestStatusCheckerImpl.java b/java/google/registry/util/RequestStatusCheckerImpl.java index 23349e64c..2e56d89ba 100644 --- a/java/google/registry/util/RequestStatusCheckerImpl.java +++ b/java/google/registry/util/RequestStatusCheckerImpl.java @@ -20,6 +20,7 @@ import com.google.appengine.api.log.LogServiceFactory; import com.google.appengine.api.log.RequestLogs; import com.google.apphosting.api.ApiProxy; import com.google.apphosting.api.ApiProxy.Environment; +import com.google.common.annotations.VisibleForTesting; import com.google.common.collect.Iterables; import java.util.Collections; import javax.inject.Inject; @@ -29,15 +30,17 @@ public class RequestStatusCheckerImpl implements RequestStatusChecker { private static final long serialVersionUID = -8161977032130865437L; - private static final FormattingLogger logger = FormattingLogger.getLoggerForCallerClass(); + @VisibleForTesting + static final FormattingLogger logger = FormattingLogger.getLoggerForCallerClass(); + + @VisibleForTesting + static LogService logService = LogServiceFactory.getLogService(); /** * The key to {@link Environment#getAttributes}'s request_log_id value. */ private static final String REQUEST_LOG_ID_KEY = "com.google.appengine.runtime.request_log_id"; - private static final LogService LOG_SERVICE = LogServiceFactory.getLogService(); - @Inject public RequestStatusCheckerImpl() {} /** @@ -53,6 +56,12 @@ public class RequestStatusCheckerImpl implements RequestStatusChecker { String requestLogId = ApiProxy.getCurrentEnvironment().getAttributes().get(REQUEST_LOG_ID_KEY).toString(); logger.infofmt("Current requestLogId: %s", requestLogId); + // We want to make sure there actually is a log to query for this request, even if the request + // dies right after this call. + // + // flushLogs() is synchronous, so once the function returns, no matter what happens next, the + // returned requestLogId will point to existing logs. + ApiProxy.flushLogs(); return requestLogId; } @@ -65,16 +74,19 @@ public class RequestStatusCheckerImpl implements RequestStatusChecker { public boolean isRunning(String requestLogId) { RequestLogs requestLogs = Iterables.getOnlyElement( - LOG_SERVICE.fetch( - LogQuery.Builder.withRequestIds( - Collections.singletonList(requestLogId))), + logService.fetch( + LogQuery.Builder + .withRequestIds(Collections.singletonList(requestLogId)) + .includeAppLogs(false) + .includeIncomplete(true)), null); - // requestLogs will be null if that requestLogId isn't found at all, which also implies it's not - // running. + // requestLogs will be null if that requestLogId isn't found at all, which can happen if the + // request is too new (it can take several seconds until the logs are available for "fetch"). + // So we have to assume it's "running" in that case. if (requestLogs == null) { logger.infofmt( - "Queried an unrecognized requestLogId %s - assume it isn't running", requestLogId); - return false; + "Queried an unrecognized requestLogId %s - assume it's running", requestLogId); + return true; } logger.infofmt( "Found logs for requestLogId %s - isFinished: %s", requestLogId, requestLogs.isFinished()); diff --git a/javatests/google/registry/util/RequestStatusCheckerImplTest.java b/javatests/google/registry/util/RequestStatusCheckerImplTest.java new file mode 100644 index 000000000..66de1e098 --- /dev/null +++ b/javatests/google/registry/util/RequestStatusCheckerImplTest.java @@ -0,0 +1,129 @@ +// Copyright 2017 The Nomulus Authors. All Rights Reserved. +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package google.registry.util; + +import static com.google.common.truth.Truth.assertThat; +import static google.registry.testing.LogsSubject.assertAboutLogs; +import static org.mockito.Matchers.argThat; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.when; + +import com.google.appengine.api.log.LogQuery; +import com.google.appengine.api.log.LogService; +import com.google.appengine.api.log.RequestLogs; +import com.google.apphosting.api.ApiProxy; +import com.google.common.collect.ImmutableList; +import com.google.common.testing.TestLogHandler; +import google.registry.testing.AppEngineRule; +import java.util.logging.Level; +import org.junit.After; +import org.junit.Before; +import org.junit.Rule; +import org.junit.Test; +import org.junit.runner.RunWith; +import org.junit.runners.JUnit4; +import org.mockito.ArgumentMatcher; + +/** Unit tests for {@link RequestStatusCheckerImpl}. */ +@RunWith(JUnit4.class) +public final class RequestStatusCheckerImplTest { + + private static final TestLogHandler logHandler = new TestLogHandler(); + + private static final RequestStatusChecker requestStatusChecker = new RequestStatusCheckerImpl(); + + /** + * Matcher for the expected LogQuery in {@link RequestStatusCheckerImpl#isRunning}. + * + * Because LogQuery doesn't have a .equals function, we have to create an actual matcher to make + * sure we have the right argument in our mocks. + */ + private static final LogQuery expectedLogQuery(final String requestLogId) { + return argThat( + new ArgumentMatcher() { + @Override + public boolean matches(Object object) { + assertThat(object).isInstanceOf(LogQuery.class); + LogQuery logQuery = (LogQuery) object; + assertThat(logQuery.getRequestIds()).containsExactly(requestLogId); + assertThat(logQuery.getIncludeAppLogs()).isFalse(); + assertThat(logQuery.getIncludeIncomplete()).isTrue(); + return true; + } + }); + } + + @Rule + public AppEngineRule appEngineRule = AppEngineRule.builder().build(); + + @Before public void setUp() { + RequestStatusCheckerImpl.logger.addHandler(logHandler); + RequestStatusCheckerImpl.logService = mock(LogService.class); + } + + @After public void tearDown() { + RequestStatusCheckerImpl.logger.removeHandler(logHandler); + } + + // If a logId is unrecognized, it could be that the log hasn't been uploaded yet - so we assume + // it's a request that has just started running recently. + @Test public void testIsRunning_unrecognized() { + when(RequestStatusCheckerImpl.logService.fetch(expectedLogQuery("12345678"))) + .thenReturn(ImmutableList.of()); + assertThat(requestStatusChecker.isRunning("12345678")).isTrue(); + assertAboutLogs() + .that(logHandler) + .hasLogAtLevelWithMessage(Level.INFO, "Queried an unrecognized requestLogId"); + } + + @Test public void testIsRunning_notFinished() { + RequestLogs requestLogs = new RequestLogs(); + requestLogs.setFinished(false); + + when(RequestStatusCheckerImpl.logService.fetch(expectedLogQuery("12345678"))) + .thenReturn(ImmutableList.of(requestLogs)); + + assertThat(requestStatusChecker.isRunning("12345678")).isTrue(); + assertAboutLogs() + .that(logHandler) + .hasLogAtLevelWithMessage(Level.INFO, "isFinished: false"); + } + + @Test public void testIsRunning_finished() { + RequestLogs requestLogs = new RequestLogs(); + requestLogs.setFinished(true); + + when(RequestStatusCheckerImpl.logService.fetch(expectedLogQuery("12345678"))) + .thenReturn(ImmutableList.of(requestLogs)); + + assertThat(requestStatusChecker.isRunning("12345678")).isFalse(); + assertAboutLogs() + .that(logHandler) + .hasLogAtLevelWithMessage(Level.INFO, "isFinished: true"); + } + + @Test public void testGetLogId_returnsRequestLogId() { + String expectedLogId = ApiProxy.getCurrentEnvironment().getAttributes().get( + "com.google.appengine.runtime.request_log_id").toString(); + assertThat(requestStatusChecker.getLogId()).isEqualTo(expectedLogId); + } + + @Test public void testGetLogId_createsLog() { + requestStatusChecker.getLogId(); + assertAboutLogs() + .that(logHandler) + .hasLogAtLevelWithMessage(Level.INFO, "Current requestLogId: "); + } +}