From c2f40df6ed815e2229e0381a993e7e94e2e651fc Mon Sep 17 00:00:00 2001 From: Simon Zeltser Date: Wed, 11 Nov 2020 11:40:08 -0800 Subject: [PATCH] fix: add default time range filter for ListLogEntries API (#304) * feat!: listLogEntries now appends default 24h filter BREAKING CHANGE: previously if the user called listLogEntries API with no parameters, the query would try to retrieve all log entries, taking up time and eventually crashing on projects with high volume logs. The new behavior complies with gcloud: if no timestamp filter was specified, it appends a filter covering last 24 hours. --- .../logging/ITimestampDefaultFilter.java | 31 ++++++++ .../com/google/cloud/logging/LoggingImpl.java | 32 +++++--- .../cloud/logging/TimestampDefaultFilter.java | 40 ++++++++++ .../google/cloud/logging/LoggingImplTest.java | 76 ++++++++++++++----- .../logging/TimestampDefaultFilterTest.java | 55 ++++++++++++++ 5 files changed, 206 insertions(+), 28 deletions(-) create mode 100644 google-cloud-logging/src/main/java/com/google/cloud/logging/ITimestampDefaultFilter.java create mode 100644 google-cloud-logging/src/main/java/com/google/cloud/logging/TimestampDefaultFilter.java create mode 100644 google-cloud-logging/src/test/java/com/google/cloud/logging/TimestampDefaultFilterTest.java diff --git a/google-cloud-logging/src/main/java/com/google/cloud/logging/ITimestampDefaultFilter.java b/google-cloud-logging/src/main/java/com/google/cloud/logging/ITimestampDefaultFilter.java new file mode 100644 index 000000000..72bb09b91 --- /dev/null +++ b/google-cloud-logging/src/main/java/com/google/cloud/logging/ITimestampDefaultFilter.java @@ -0,0 +1,31 @@ +/* + * Copyright 2020 Google LLC + * + * 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 com.google.cloud.logging; + +/** + * Encapsulates implementation of default time filter. This is needed for testing since we can't + * mock static classes with EasyMock + */ +public interface ITimestampDefaultFilter { + + /** + * Creates a default filter with timestamp to query Cloud Logging + * + * @return The filter using timestamp field + */ + String createDefaultTimestampFilter(); +} diff --git a/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingImpl.java b/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingImpl.java index f5edb3155..661166cd7 100644 --- a/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingImpl.java +++ b/google-cloud-logging/src/main/java/com/google/cloud/logging/LoggingImpl.java @@ -77,9 +77,7 @@ import com.google.logging.v2.WriteLogEntriesRequest; import com.google.logging.v2.WriteLogEntriesResponse; import com.google.protobuf.Empty; -import java.util.ArrayList; -import java.util.List; -import java.util.Map; +import java.util.*; import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.ExecutionException; import java.util.concurrent.TimeUnit; @@ -111,6 +109,9 @@ public Void apply(WriteLogEntriesResponse input) { }; private static final ThreadLocal inWriteCall = new ThreadLocal<>(); + @VisibleForTesting + static ITimestampDefaultFilter defaultTimestampFilterCreator = new TimestampDefaultFilter(); + LoggingImpl(LoggingOptions options) { super(options); rpc = options.getLoggingRpcV2(); @@ -705,8 +706,7 @@ public void write(Iterable logEntries, WriteOption... options) { public void flush() { // BUG(1795): We should force batcher to issue RPC call for buffered messages, // so the code below doesn't wait uselessly. - ArrayList> writesToFlush = new ArrayList<>(); - writesToFlush.addAll(pendingWrites.values()); + ArrayList> writesToFlush = new ArrayList<>(pendingWrites.values()); try { ApiFutures.allAsList(writesToFlush).get(FLUSH_WAIT_TIMEOUT_SECONDS, TimeUnit.SECONDS); @@ -779,9 +779,21 @@ static ListLogEntriesRequest listLogEntriesRequest( builder.setOrderBy(orderBy); } String filter = FILTER.get(options); + // Make sure timestamp filter is either explicitly specified or we add a default time filter + // of 24 hours back to be inline with gcloud behavior for the same API if (filter != null) { + if (!filter.toLowerCase().contains("timestamp")) { + filter = + String.format( + "%s AND %s", filter, defaultTimestampFilterCreator.createDefaultTimestampFilter()); + } builder.setFilter(filter); + } else { + // If filter is not specified, default filter is looking back 24 hours in line with gcloud + // behavior + builder.setFilter(defaultTimestampFilterCreator.createDefaultTimestampFilter()); } + return builder.build(); } @@ -794,16 +806,16 @@ private static ApiFuture> listLogEntriesAsync( list, new Function>() { @Override - public AsyncPage apply(ListLogEntriesResponse listLogEntrysResponse) { + public AsyncPage apply(ListLogEntriesResponse listLogEntriesResponse) { List entries = - listLogEntrysResponse.getEntriesList() == null + listLogEntriesResponse.getEntriesList() == null ? ImmutableList.of() : Lists.transform( - listLogEntrysResponse.getEntriesList(), LogEntry.FROM_PB_FUNCTION); + listLogEntriesResponse.getEntriesList(), LogEntry.FROM_PB_FUNCTION); String cursor = - listLogEntrysResponse.getNextPageToken().equals("") + listLogEntriesResponse.getNextPageToken().equals("") ? null - : listLogEntrysResponse.getNextPageToken(); + : listLogEntriesResponse.getNextPageToken(); return new AsyncPageImpl<>( new LogEntryPageFetcher(serviceOptions, cursor, options), cursor, entries); } diff --git a/google-cloud-logging/src/main/java/com/google/cloud/logging/TimestampDefaultFilter.java b/google-cloud-logging/src/main/java/com/google/cloud/logging/TimestampDefaultFilter.java new file mode 100644 index 000000000..5734ddb0a --- /dev/null +++ b/google-cloud-logging/src/main/java/com/google/cloud/logging/TimestampDefaultFilter.java @@ -0,0 +1,40 @@ +/* + * Copyright 2020 Google LLC + * + * 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 com.google.cloud.logging; + +import java.text.DateFormat; +import java.text.SimpleDateFormat; +import java.util.Calendar; +import java.util.Date; +import java.util.TimeZone; + +public class TimestampDefaultFilter implements ITimestampDefaultFilter { + @Override + public String createDefaultTimestampFilter() { + DateFormat rfcDateFormat = new SimpleDateFormat("yyyy-MM-dd'T'HH:mm:ss.SSS'Z'"); + rfcDateFormat.setTimeZone(TimeZone.getTimeZone("UTC")); + return "timestamp>=\"" + rfcDateFormat.format(yesterday()) + "\""; + } + + private Date yesterday() { + TimeZone timeZone = TimeZone.getTimeZone("UTC"); + Calendar calendar = Calendar.getInstance(timeZone); + calendar.add(Calendar.DATE, -1); + + return calendar.getTime(); + } +} diff --git a/google-cloud-logging/src/test/java/com/google/cloud/logging/LoggingImplTest.java b/google-cloud-logging/src/test/java/com/google/cloud/logging/LoggingImplTest.java index 8b238fda0..fe34719d8 100644 --- a/google-cloud-logging/src/test/java/com/google/cloud/logging/LoggingImplTest.java +++ b/google-cloud-logging/src/test/java/com/google/cloud/logging/LoggingImplTest.java @@ -154,7 +154,7 @@ public com.google.api.MonitoredResourceDescriptor apply( private static final String NEXT_CURSOR = "nextCursor"; private static final Boolean DISABLED = Boolean.FALSE; private static final Timestamp EXCLUSION_CREATED_TIME = fromMillis(System.currentTimeMillis()); - private static final Timestamp EXCLUSION_UPDATED_TIME = fromMillis(System.currentTimeMillis());; + private static final Timestamp EXCLUSION_UPDATED_TIME = fromMillis(System.currentTimeMillis()); private static final Exclusion EXCLUSION = Exclusion.newBuilder(EXCLUSION_NAME, EXCLUSION_FILTER) .setDisabled(DISABLED) @@ -185,6 +185,18 @@ public void setUp() { .setServiceRpcFactory(rpcFactoryMock) .setRetrySettings(ServiceOptions.getNoRetrySettings()) .build(); + + // By default when calling ListLogEntries, we append a filter of last 24 hours. + // However when testing, the time when it was called by the test and by the method + // implementation might differ by microseconds so we use the same time filter implementation + // for test and in "real" method + LoggingImpl.defaultTimestampFilterCreator = + new ITimestampDefaultFilter() { + @Override + public String createDefaultTimestampFilter() { + return "timestamp>=\"2020-10-30T15:39:09Z\""; + } + }; } @After @@ -1585,7 +1597,7 @@ public void testDeleteLog_Null() { } @Test - public void testDeleteLogAync() throws ExecutionException, InterruptedException { + public void testDeleteLogAsync() throws ExecutionException, InterruptedException { DeleteLogRequest request = DeleteLogRequest.newBuilder().setLogName(LOG_NAME_PB).build(); ApiFuture response = ApiFutures.immediateFuture(Empty.getDefaultInstance()); EasyMock.expect(loggingRpcMock.delete(request)).andReturn(response); @@ -1621,7 +1633,7 @@ public void testWriteLogEntries() { } @Test - public void testWriteLogEntriesDoesnotEnableFlushByDefault() { + public void testWriteLogEntriesDoesNotEnableFlushByDefault() { WriteLogEntriesRequest request = WriteLogEntriesRequest.newBuilder() .addAllEntries( @@ -1679,7 +1691,7 @@ public void testWriteLogEntriesWithOptions() { } @Test - public void testWriteLogEntriesAsync() throws ExecutionException, InterruptedException { + public void testWriteLogEntriesAsync() { WriteLogEntriesRequest request = WriteLogEntriesRequest.newBuilder() .addAllEntries( @@ -1723,8 +1735,7 @@ public void testListLogEntries() { String cursor = "cursor"; EasyMock.replay(rpcFactoryMock); logging = options.getService(); - ListLogEntriesRequest request = - ListLogEntriesRequest.newBuilder().addResourceNames(PROJECT_PB).build(); + List entriesList = ImmutableList.of(LOG_ENTRY1, LOG_ENTRY2); ListLogEntriesResponse response = ListLogEntriesResponse.newBuilder() @@ -1732,7 +1743,8 @@ public void testListLogEntries() { .addAllEntries(Lists.transform(entriesList, LogEntry.toPbFunction(PROJECT))) .build(); ApiFuture futureResponse = ApiFutures.immediateFuture(response); - EasyMock.expect(loggingRpcMock.list(request)).andReturn(futureResponse); + EasyMock.expect(loggingRpcMock.list(EasyMock.anyObject(ListLogEntriesRequest.class))) + .andReturn(futureResponse); EasyMock.replay(loggingRpcMock); Page page = logging.listLogEntries(); assertEquals(cursor, page.getNextPageToken()); @@ -1744,11 +1756,18 @@ public void testListLogEntriesNextPage() throws ExecutionException, InterruptedE String cursor1 = "cursor"; EasyMock.replay(rpcFactoryMock); logging = options.getService(); + + String defaultTimeFilter = + LoggingImpl.defaultTimestampFilterCreator.createDefaultTimestampFilter(); ListLogEntriesRequest request1 = - ListLogEntriesRequest.newBuilder().addResourceNames(PROJECT_PB).build(); + ListLogEntriesRequest.newBuilder() + .addResourceNames(PROJECT_PB) + .setFilter(defaultTimeFilter) + .build(); ListLogEntriesRequest request2 = ListLogEntriesRequest.newBuilder() .addResourceNames(PROJECT_PB) + .setFilter(defaultTimeFilter) .setPageToken(cursor1) .build(); List descriptorList1 = ImmutableList.of(LOG_ENTRY1, LOG_ENTRY2); @@ -1785,7 +1804,11 @@ public void testListLogEntriesEmpty() { EasyMock.replay(rpcFactoryMock); logging = options.getService(); ListLogEntriesRequest request = - ListLogEntriesRequest.newBuilder().addResourceNames(PROJECT_PB).build(); + ListLogEntriesRequest.newBuilder() + .addResourceNames(PROJECT_PB) + .setFilter(LoggingImpl.defaultTimestampFilterCreator.createDefaultTimestampFilter()) + .build(); + List entriesList = ImmutableList.of(); ListLogEntriesResponse response = ListLogEntriesResponse.newBuilder() @@ -1809,7 +1832,10 @@ public void testListLogEntriesWithOptions() { ListLogEntriesRequest.newBuilder() .addResourceNames(PROJECT_PB) .setOrderBy("timestamp desc") - .setFilter("logName:syslog") + .setFilter( + String.format( + "logName:syslog AND %s", + LoggingImpl.defaultTimestampFilterCreator.createDefaultTimestampFilter())) .build(); List entriesList = ImmutableList.of(LOG_ENTRY1, LOG_ENTRY2); ListLogEntriesResponse response = @@ -1834,7 +1860,10 @@ public void testListLogEntriesAsync() throws ExecutionException, InterruptedExce EasyMock.replay(rpcFactoryMock); logging = options.getService(); ListLogEntriesRequest request = - ListLogEntriesRequest.newBuilder().addResourceNames(PROJECT_PB).build(); + ListLogEntriesRequest.newBuilder() + .addResourceNames(PROJECT_PB) + .setFilter(LoggingImpl.defaultTimestampFilterCreator.createDefaultTimestampFilter()) + .build(); List entriesList = ImmutableList.of(LOG_ENTRY1, LOG_ENTRY2); ListLogEntriesResponse response = ListLogEntriesResponse.newBuilder() @@ -1855,10 +1884,14 @@ public void testListLogEntriesAsyncNextPage() { EasyMock.replay(rpcFactoryMock); logging = options.getService(); ListLogEntriesRequest request1 = - ListLogEntriesRequest.newBuilder().addResourceNames(PROJECT_PB).build(); + ListLogEntriesRequest.newBuilder() + .addResourceNames(PROJECT_PB) + .setFilter(LoggingImpl.defaultTimestampFilterCreator.createDefaultTimestampFilter()) + .build(); ListLogEntriesRequest request2 = ListLogEntriesRequest.newBuilder() .addResourceNames(PROJECT_PB) + .setFilter(LoggingImpl.defaultTimestampFilterCreator.createDefaultTimestampFilter()) .setPageToken(cursor1) .build(); List descriptorList1 = ImmutableList.of(LOG_ENTRY1, LOG_ENTRY2); @@ -1890,12 +1923,15 @@ public void testListLogEntriesAsyncNextPage() { } @Test - public void testListLogEntriesAyncEmpty() throws ExecutionException, InterruptedException { + public void testListLogEntriesAsyncEmpty() throws ExecutionException, InterruptedException { String cursor = "cursor"; EasyMock.replay(rpcFactoryMock); logging = options.getService(); ListLogEntriesRequest request = - ListLogEntriesRequest.newBuilder().addResourceNames(PROJECT_PB).build(); + ListLogEntriesRequest.newBuilder() + .addResourceNames(PROJECT_PB) + .setFilter(LoggingImpl.defaultTimestampFilterCreator.createDefaultTimestampFilter()) + .build(); List entriesList = ImmutableList.of(); ListLogEntriesResponse response = ListLogEntriesResponse.newBuilder() @@ -1915,11 +1951,15 @@ public void testListLogEntriesAsyncWithOptions() throws ExecutionException, Inte String cursor = "cursor"; EasyMock.replay(rpcFactoryMock); logging = options.getService(); + String filter = + String.format( + "logName:syslog AND %s", + LoggingImpl.defaultTimestampFilterCreator.createDefaultTimestampFilter()); ListLogEntriesRequest request = ListLogEntriesRequest.newBuilder() .addResourceNames(PROJECT_PB) .setOrderBy("timestamp desc") - .setFilter("logName:syslog") + .setFilter(filter) .build(); List entriesList = ImmutableList.of(LOG_ENTRY1, LOG_ENTRY2); ListLogEntriesResponse response = @@ -1933,7 +1973,7 @@ public void testListLogEntriesAsyncWithOptions() throws ExecutionException, Inte AsyncPage page = logging .listLogEntriesAsync( - EntryListOption.filter("logName:syslog"), + EntryListOption.filter(filter), EntryListOption.sortOrder(SortingField.TIMESTAMP, Logging.SortingOrder.DESCENDING)) .get(); assertEquals(cursor, page.getNextPageToken()); @@ -2011,8 +2051,8 @@ public void run() { }; threads[i].start(); } - for (int i = 0; i < threads.length; i++) { - threads[i].join(); + for (Thread thread : threads) { + thread.join(); } assertSame(0, exceptions.get()); } diff --git a/google-cloud-logging/src/test/java/com/google/cloud/logging/TimestampDefaultFilterTest.java b/google-cloud-logging/src/test/java/com/google/cloud/logging/TimestampDefaultFilterTest.java new file mode 100644 index 000000000..49618c41f --- /dev/null +++ b/google-cloud-logging/src/test/java/com/google/cloud/logging/TimestampDefaultFilterTest.java @@ -0,0 +1,55 @@ +/* + * Copyright 2020 Google LLC + * + * 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 com.google.cloud.logging; + +import static org.junit.Assert.assertTrue; +import static org.junit.Assert.fail; + +import java.text.DateFormat; +import java.text.SimpleDateFormat; +import java.util.Calendar; +import java.util.Date; +import java.util.TimeZone; +import javax.management.timer.Timer; +import org.junit.Test; + +public class TimestampDefaultFilterTest { + + @Test + public void DefaultTimestampFilterTest() { + ITimestampDefaultFilter filter = new TimestampDefaultFilter(); + + TimeZone timeZone = TimeZone.getTimeZone("UTC"); + Calendar calendar = Calendar.getInstance(timeZone); + calendar.add(Calendar.DATE, -1); + Date expected = calendar.getTime(); + + // Timestamp filter exists + String defaultFilter = filter.createDefaultTimestampFilter(); + assertTrue(defaultFilter.contains("timestamp>=")); + + // Time is last 24 hours + try { + DateFormat rfcDateFormat = new SimpleDateFormat("yyyy-MM-dd'T'HH:mm:ss.SSS'Z'"); + rfcDateFormat.setTimeZone(TimeZone.getTimeZone("UTC")); + Date actual = rfcDateFormat.parse(defaultFilter.substring(12, defaultFilter.length() - 1)); + assertTrue(Math.abs(expected.getTime() - actual.getTime()) < Timer.ONE_MINUTE); + } catch (java.text.ParseException ex) { + fail(); // Just fail if exception is thrown + } + } +}