From a42fe9bfb00d73db1a906fcc278505e3f53c934f Mon Sep 17 00:00:00 2001 From: Jon Chambers Date: Tue, 23 Nov 2021 15:43:21 -0500 Subject: [PATCH] Add crawler names to log messages --- .../textsecuregcm/WhisperServerService.java | 7 ++++-- .../storage/AccountDatabaseCrawler.java | 15 +++++++----- ...AccountDatabaseCrawlerIntegrationTest.java | 2 +- .../storage/AccountDatabaseCrawlerTest.java | 23 ++++++++----------- 4 files changed, 25 insertions(+), 22 deletions(-) diff --git a/service/src/main/java/org/whispersystems/textsecuregcm/WhisperServerService.java b/service/src/main/java/org/whispersystems/textsecuregcm/WhisperServerService.java index 51963be92..48e80597e 100644 --- a/service/src/main/java/org/whispersystems/textsecuregcm/WhisperServerService.java +++ b/service/src/main/java/org/whispersystems/textsecuregcm/WhisperServerService.java @@ -542,7 +542,9 @@ public class WhisperServerService extends Application listeners, int chunkSize, long chunkIntervalMs) { + this.name = name; this.accounts = accounts; this.chunkSize = chunkSize; this.chunkIntervalMs = chunkIntervalMs; @@ -82,7 +85,7 @@ public class AccountDatabaseCrawler implements Managed, Runnable { accelerated = doPeriodicWork(); sleepWhileRunning(accelerated ? ACCELERATED_CHUNK_INTERVAL : chunkIntervalMs); } catch (Throwable t) { - logger.warn("error in database crawl: {}: {}", t.getClass().getSimpleName(), t.getMessage(), t); + logger.warn("{}: error in database crawl: {}: {}", name, t.getClass().getSimpleName(), t.getMessage(), t); Util.sleep(10000); } } @@ -106,7 +109,7 @@ public class AccountDatabaseCrawler implements Managed, Runnable { final long endTimeMs = System.currentTimeMillis(); final long sleepIntervalMs = chunkIntervalMs - (endTimeMs - startTimeMs); if (sleepIntervalMs > 0) { - logger.debug("Sleeping {}ms", sleepIntervalMs); + logger.debug("{}: Sleeping {}ms", name, sleepIntervalMs); sleepWhileRunning(sleepIntervalMs); } } finally { @@ -123,19 +126,19 @@ public class AccountDatabaseCrawler implements Managed, Runnable { final Optional fromUuid = getLastUuid(); if (fromUuid.isEmpty()) { - logger.info("Started crawl"); + logger.info("{}: Started crawl", name); listeners.forEach(AccountDatabaseCrawlerListener::onCrawlStart); } final AccountCrawlChunk chunkAccounts = readChunk(fromUuid, chunkSize); if (chunkAccounts.getAccounts().isEmpty()) { - logger.info("Finished crawl"); + logger.info("{}: Finished crawl", name); listeners.forEach(listener -> listener.onCrawlEnd(fromUuid)); cacheLastUuid(Optional.empty()); cache.setAccelerated(false); } else { - logger.debug("Processing chunk"); + logger.debug("{}: Processing chunk", name); try { for (AccountDatabaseCrawlerListener listener : listeners) { listener.timeAndProcessCrawlChunk(fromUuid, chunkAccounts.getAccounts()); diff --git a/service/src/test/java/org/whispersystems/textsecuregcm/storage/AccountDatabaseCrawlerIntegrationTest.java b/service/src/test/java/org/whispersystems/textsecuregcm/storage/AccountDatabaseCrawlerIntegrationTest.java index 3dfadaba3..636677fc7 100644 --- a/service/src/test/java/org/whispersystems/textsecuregcm/storage/AccountDatabaseCrawlerIntegrationTest.java +++ b/service/src/test/java/org/whispersystems/textsecuregcm/storage/AccountDatabaseCrawlerIntegrationTest.java @@ -58,7 +58,7 @@ public class AccountDatabaseCrawlerIntegrationTest extends AbstractRedisClusterT .thenReturn(new AccountCrawlChunk(Collections.emptyList(), null)); final AccountDatabaseCrawlerCache crawlerCache = new AccountDatabaseCrawlerCache(getRedisCluster(), "test"); - accountDatabaseCrawler = new AccountDatabaseCrawler(accountsManager, crawlerCache, List.of(listener), CHUNK_SIZE, + accountDatabaseCrawler = new AccountDatabaseCrawler("test", accountsManager, crawlerCache, List.of(listener), CHUNK_SIZE, CHUNK_INTERVAL_MS); } diff --git a/service/src/test/java/org/whispersystems/textsecuregcm/tests/storage/AccountDatabaseCrawlerTest.java b/service/src/test/java/org/whispersystems/textsecuregcm/tests/storage/AccountDatabaseCrawlerTest.java index 0b513d8ca..27a9cbbdd 100644 --- a/service/src/test/java/org/whispersystems/textsecuregcm/tests/storage/AccountDatabaseCrawlerTest.java +++ b/service/src/test/java/org/whispersystems/textsecuregcm/tests/storage/AccountDatabaseCrawlerTest.java @@ -18,11 +18,10 @@ import static org.mockito.Mockito.verifyNoInteractions; import static org.mockito.Mockito.verifyNoMoreInteractions; import static org.mockito.Mockito.when; -import java.util.Arrays; import java.util.Collections; +import java.util.List; import java.util.Optional; import java.util.UUID; -import java.util.concurrent.ExecutorService; import org.junit.jupiter.api.BeforeEach; import org.junit.jupiter.api.Test; import org.whispersystems.textsecuregcm.storage.Account; @@ -48,10 +47,8 @@ class AccountDatabaseCrawlerTest { private final AccountDatabaseCrawlerListener listener = mock(AccountDatabaseCrawlerListener.class); private final AccountDatabaseCrawlerCache cache = mock(AccountDatabaseCrawlerCache.class); - private final ExecutorService chunkPreReadExecutorService = mock(ExecutorService.class); - - private final AccountDatabaseCrawler crawler = new AccountDatabaseCrawler(accounts, cache, Arrays.asList(listener), - CHUNK_SIZE, CHUNK_INTERVAL_MS); + private final AccountDatabaseCrawler crawler = + new AccountDatabaseCrawler("test", accounts, cache, List.of(listener), CHUNK_SIZE, CHUNK_INTERVAL_MS); @BeforeEach void setup() { @@ -59,9 +56,9 @@ class AccountDatabaseCrawlerTest { when(account2.getUuid()).thenReturn(ACCOUNT2); when(accounts.getAllFromDynamo(anyInt())).thenReturn( - new AccountCrawlChunk(Arrays.asList(account1, account2), ACCOUNT2)); + new AccountCrawlChunk(List.of(account1, account2), ACCOUNT2)); when(accounts.getAllFromDynamo(eq(ACCOUNT1), anyInt())).thenReturn( - new AccountCrawlChunk(Arrays.asList(account2), ACCOUNT2)); + new AccountCrawlChunk(List.of(account2), ACCOUNT2)); when(accounts.getAllFromDynamo(eq(ACCOUNT2), anyInt())).thenReturn( new AccountCrawlChunk(Collections.emptyList(), null)); @@ -85,7 +82,7 @@ class AccountDatabaseCrawlerTest { verify(accounts, times(1)).getAllFromDynamo(eq(CHUNK_SIZE)); verify(accounts, times(0)).getAllFromDynamo(any(UUID.class), eq(CHUNK_SIZE)); verify(account1, times(0)).getUuid(); - verify(listener, times(1)).timeAndProcessCrawlChunk(eq(Optional.empty()), eq(Arrays.asList(account1, account2))); + verify(listener, times(1)).timeAndProcessCrawlChunk(eq(Optional.empty()), eq(List.of(account1, account2))); verify(cache, times(0)).setLastUuid(eq(Optional.of(ACCOUNT2))); verify(cache, times(1)).setLastUuidDynamo(eq(Optional.of(ACCOUNT2))); verify(cache, times(1)).isAccelerated(); @@ -111,7 +108,7 @@ class AccountDatabaseCrawlerTest { verify(cache, times(1)).getLastUuidDynamo(); verify(accounts, times(0)).getAllFromDynamo(eq(CHUNK_SIZE)); verify(accounts, times(1)).getAllFromDynamo(eq(ACCOUNT1), eq(CHUNK_SIZE)); - verify(listener, times(1)).timeAndProcessCrawlChunk(eq(Optional.of(ACCOUNT1)), eq(Arrays.asList(account2))); + verify(listener, times(1)).timeAndProcessCrawlChunk(eq(Optional.of(ACCOUNT1)), eq(List.of(account2))); verify(cache, times(0)).setLastUuid(eq(Optional.of(ACCOUNT2))); verify(cache, times(1)).setLastUuidDynamo(eq(Optional.of(ACCOUNT2))); verify(cache, times(1)).isAccelerated(); @@ -139,7 +136,7 @@ class AccountDatabaseCrawlerTest { verify(cache, times(1)).getLastUuidDynamo(); verify(accounts, times(0)).getAllFromDynamo(eq(CHUNK_SIZE)); verify(accounts, times(1)).getAllFromDynamo(eq(ACCOUNT1), eq(CHUNK_SIZE)); - verify(listener, times(1)).timeAndProcessCrawlChunk(eq(Optional.of(ACCOUNT1)), eq(Arrays.asList(account2))); + verify(listener, times(1)).timeAndProcessCrawlChunk(eq(Optional.of(ACCOUNT1)), eq(List.of(account2))); verify(cache, times(0)).setLastUuid(eq(Optional.of(ACCOUNT2))); verify(cache, times(1)).setLastUuidDynamo(eq(Optional.of(ACCOUNT2))); verify(cache, times(1)).isAccelerated(); @@ -158,7 +155,7 @@ class AccountDatabaseCrawlerTest { when(cache.getLastUuid()).thenReturn(Optional.of(ACCOUNT1)); when(cache.getLastUuidDynamo()).thenReturn(Optional.of(ACCOUNT1)); doThrow(AccountDatabaseCrawlerRestartException.class).when(listener) - .timeAndProcessCrawlChunk(eq(Optional.of(ACCOUNT1)), eq(Arrays.asList(account2))); + .timeAndProcessCrawlChunk(eq(Optional.of(ACCOUNT1)), eq(List.of(account2))); boolean accelerated = crawler.doPeriodicWork(); assertThat(accelerated).isFalse(); @@ -169,7 +166,7 @@ class AccountDatabaseCrawlerTest { verify(accounts, times(0)).getAllFromDynamo(eq(CHUNK_SIZE)); verify(accounts, times(1)).getAllFromDynamo(eq(ACCOUNT1), eq(CHUNK_SIZE)); verify(account2, times(0)).getNumber(); - verify(listener, times(1)).timeAndProcessCrawlChunk(eq(Optional.of(ACCOUNT1)), eq(Arrays.asList(account2))); + verify(listener, times(1)).timeAndProcessCrawlChunk(eq(Optional.of(ACCOUNT1)), eq(List.of(account2))); verify(cache, times(0)).setLastUuid(eq(Optional.empty())); verify(cache, times(1)).setLastUuidDynamo(eq(Optional.empty())); verify(cache, times(1)).setAccelerated(false);