From fef49f93b8d95d80ae9475aa52c71206adcb2e2f Mon Sep 17 00:00:00 2001 From: Jason Borg Date: Fri, 2 Dec 2022 18:10:09 +0000 Subject: [PATCH] feat: Add active debuggee support. The Firebase client now adds two new fields to the Debuggee entry in the Firebase RTDB, `registrationTimeMsec` and `lastUpdateTimeMsec`. The first time the Debuggee entry is written to the RTDB, both fields are set. Thereafter only the `lastUpdateTimeMsec` will be changed, which is done periodically every hour when the agent is running continuously, it is also updated when the agent first starts up. This is in support of https://github.com/GoogleCloudPlatform/snapshot-debugger/issues/76. --- .../cdbg/debuglets/java/FirebaseClient.java | 175 +++++++--- .../debuglets/java/FirebaseClientTest.java | 325 +++++++++++++++++- 2 files changed, 439 insertions(+), 61 deletions(-) diff --git a/src/agent/internals/src/main/java/com/google/devtools/cdbg/debuglets/java/FirebaseClient.java b/src/agent/internals/src/main/java/com/google/devtools/cdbg/debuglets/java/FirebaseClient.java index 4d89ae82..07c869df 100644 --- a/src/agent/internals/src/main/java/com/google/devtools/cdbg/debuglets/java/FirebaseClient.java +++ b/src/agent/internals/src/main/java/com/google/devtools/cdbg/debuglets/java/FirebaseClient.java @@ -42,12 +42,15 @@ import java.nio.file.Paths; import java.security.MessageDigest; import java.security.NoSuchAlgorithmException; +import java.time.Duration; import java.util.ArrayList; import java.util.Collections; import java.util.HashMap; import java.util.List; import java.util.Map; import java.util.SortedSet; +import java.util.Timer; +import java.util.TimerTask; import java.util.TreeMap; import java.util.TreeSet; import java.util.concurrent.ArrayBlockingQueue; @@ -55,6 +58,8 @@ import java.util.concurrent.TimeUnit; class FirebaseClient implements HubClient { + static final Duration MARK_DEBUGGEE_ACTIVE_PERIOD = Duration.ofHours(1); + // Note, the Debuggee class is to be serialized automatically by the Firebase library. To support // this the following is purposely done here: // 1. All data members are public. @@ -66,6 +71,8 @@ static class Debuggee { public Map labels; public String agentVersion; public List> sourceContexts; + public final Map registrationTimeMsec = ServerValue.TIMESTAMP; + public final Map lastUpdateTimeMsec = ServerValue.TIMESTAMP; public void setDebuggeeId(String debuggeeId) { this.id = debuggeeId; @@ -119,18 +126,20 @@ static class Timeout { } ; - /** The timeouts are configurable to allow the unit test to set lower timeouts */ + /** The timeouts are configurable to allow the unit test to set lower values */ static class TimeoutConfig { TimeoutConfig(long value, TimeUnit units) { this.setDebuggee = new Timeout(value, units); this.setBreakpoint = new Timeout(value, units); this.getSchemaVersion = new Timeout(value, units); + this.getDebuggee = new Timeout(value, units); this.listActiveBreakpoints = new Timeout(value, units); } Timeout setDebuggee; Timeout setBreakpoint; Timeout getSchemaVersion; + Timeout getDebuggee; Timeout listActiveBreakpoints; } ; @@ -311,6 +320,9 @@ public FirebaseDatabase getDbInstance(FirebaseApp app) { .serializeNulls() .create(); + private Timer markDebuggeeActiveTimer; + private final Duration markDebuggeeActivePeriod; + /** Default constructor using environment provided by {@link GcpEnvironment}. */ public FirebaseClient() { this.metadata = GcpEnvironment.getMetadataQuery(); @@ -320,7 +332,12 @@ public FirebaseClient() { // Initialize everything with the same timeout, then make specific overrides where desired. this.timeouts = new TimeoutConfig(30, TimeUnit.SECONDS); + + // We lower this timeout, as it's only used when probing a potential DB address to see if it + // exists and is configured for Snapshot Debugger use. this.timeouts.getSchemaVersion.value = 10; + + this.markDebuggeeActivePeriod = MARK_DEBUGGEE_ACTIVE_PERIOD; } /** @@ -330,19 +347,22 @@ public FirebaseClient() { * @param classPathLookup read and explore application resources * @param labels debuggee labels (such as version and module) * @param firebaseStaticWrappers implementation of Firebase static api calls - * @param the timeout values to use + * @param timeouts the timeout values to use + * @param markDebuggeeActivePeriod the period to use for marking the debuggee active */ public FirebaseClient( MetadataQuery metadata, ClassPathLookup classPathLookup, Map labels, FirebaseStaticWrappers firebaseStaticWrappers, - TimeoutConfig timeouts) { + TimeoutConfig timeouts, + Duration markDebuggeeActivePeriod) { this.metadata = metadata; this.classPathLookup = classPathLookup; this.labels = labels; this.firebaseStaticWrappers = firebaseStaticWrappers; this.timeouts = timeouts; + this.markDebuggeeActivePeriod = markDebuggeeActivePeriod; } @Override @@ -361,12 +381,34 @@ public boolean registerDebuggee(Map extraDebuggeeLabels) throws Debuggee debuggee = getDebuggeeInfo(extraDebuggeeLabels); setDebuggeeId(debuggee.id); - String debuggeePath = "cdbg/debuggees/" + getDebuggeeId(); - setDbValue(debuggeePath, debuggee, timeouts.setDebuggee); + String debuggeePath = getDebuggeeDbPath(); + String registrationTimePath = debuggeePath + "/registrationTimeMsec"; + + boolean isDebuggeeAlreadyRegistered = + getDbValue( + this.firebaseApp, + this.firebaseStaticWrappers, + registrationTimePath, + timeouts.getDebuggee) + != null; + + if (isDebuggeeAlreadyRegistered) { + infofmt("Debuggee %s is already present in the RTDB, marking it active", getDebuggeeId()); + markDebuggeeActive(); + } else { + // Note, no need to update the lastUpdateTimeMsec field of the Debuggee in the RTDB, below we + // start the markDebuggeeActiveTimer, it will schecule the first update right away with no + // delay. + infofmt("Debuggee %s is not yet present in the RTDB, sending it.", getDebuggeeId()); + setDbValue(debuggeePath, debuggee, timeouts.setDebuggee); + } registerActiveBreakpointListener(); isRegistered = true; + // Start the timer after setting isRegistered to true. + startMarkDebuggeeActiveTimer(); + infofmt( "Debuggee %s, registered %s, agent version: %s", getDebuggeeId(), GSON.toJsonTree(debuggee), GcpDebugletVersion.VERSION); @@ -577,6 +619,7 @@ public boolean isEnabled() { public void shutdown() { infofmt("FirebaseClient::shutdown() begin"); isShutdown = true; + stopMarkDebuggeeActiveTimer(); metadata.shutdown(); unregisterActiveBreakpointListener(); deleteFirebaseApp(); @@ -593,6 +636,10 @@ private void setDebuggeeId(String id) { debuggeeId = id; } + public String getDebuggeeDbPath() { + return "cdbg/debuggees/" + getDebuggeeId(); + } + /** * Fills in the debuggee registration request message. * @@ -912,11 +959,7 @@ public void onDataChange(DataSnapshot dataSnapshot) { @Override public void onCancelled(DatabaseError error) { warnfmt("Database subscription error: %s", error.getMessage()); - - // This will force listActiveBreakpoints() to throw an exception and get the native - // agent code to begin calling registerDebuggee() again so the agent code can get - // back to a working registered state. - isRegistered = false; + forceReregistration(); } }); } @@ -928,6 +971,55 @@ synchronized void unregisterActiveBreakpointListener() { } } + private void markDebuggeeActive() throws Exception { + String lastUpdateTimeMsecPath = getDebuggeeDbPath() + "/lastUpdateTimeMsec"; + setDbValue(lastUpdateTimeMsecPath, ServerValue.TIMESTAMP, timeouts.setDebuggee); + } + + private void forceReregistration() { + // This will force listActiveBreakpoints() to throw an exception and get the native agent code + // to begin calling registerDebuggee() again so the agent code can get back to a working + // registered state. + isRegistered = false; + } + + private void startMarkDebuggeeActiveTimer() { + if (markDebuggeeActiveTimer != null) { + return; + } + + markDebuggeeActiveTimer = new Timer(); + + markDebuggeeActiveTimer.scheduleAtFixedRate( + new TimerTask() { + @Override + public void run() { + if (!isRegistered) { + return; + } + + try { + markDebuggeeActive(); + } catch (Exception e) { + warnfmt("An unexpected error occurred trying to mark the debuggee active: ", e); + forceReregistration(); + } + } + }, + // We wait for the first update as the registerDebuggee() handles marking the debuggee + // active + // initially. + /* delay= */ markDebuggeeActivePeriod.toMillis(), + /* period= */ markDebuggeeActivePeriod.toMillis()); + } + + private void stopMarkDebuggeeActiveTimer() { + if (markDebuggeeActiveTimer != null) { + markDebuggeeActiveTimer.cancel(); + markDebuggeeActiveTimer = null; + } + } + /** * Helper to set the data at a given path in the Firebase RTDB. Returns normally on success, * throws an Exception on timeout or a write error. @@ -991,45 +1083,42 @@ private static Object getDbValue( infofmt("Beginning Firebase Database read operation at '%s'", path); - ValueEventListener listener = null; - final ArrayBlockingQueue resultObtained = new ArrayBlockingQueue<>(1); final ArrayList obtainedValue = new ArrayList<>(); - try { - dbRef.addValueEventListener( - new ValueEventListener() { - @Override - public void onDataChange(DataSnapshot dataSnapshot) { - Object value = dataSnapshot.getValue(); - infofmt( - "Response obtained, data was %s found at %s", value == null ? "not" : "", path); - - obtainedValue.add(value); - resultObtained.offer(Boolean.TRUE); - } + dbRef.addListenerForSingleValueEvent( + new ValueEventListener() { + @Override + public void onDataChange(DataSnapshot dataSnapshot) { + Object value = dataSnapshot.getValue(); + infofmt("Response obtained, data was %s found at %s", value == null ? "not" : "", path); - @Override - public void onCancelled(DatabaseError error) { - warnfmt("Database subscription error: %s", error.getMessage()); - resultObtained.offer(Boolean.FALSE); - } - }); + obtainedValue.add(value); + resultObtained.offer(Boolean.TRUE); + } - // Returns null on timeout. - Boolean isSuccess = resultObtained.poll(timeout.value, timeout.units); + @Override + public void onCancelled(DatabaseError error) { + warnfmt("Database subscription error: %s", error.getMessage()); + resultObtained.offer(Boolean.FALSE); + } + }); - // null will be returned on read timeout. - if (isSuccess == null) { - infofmt("Read from %s timed out after %d %s", path, timeout.value, timeout.units); - throw new Exception("Read timed out"); - } else if (!isSuccess) { - throw new Exception("Error occurred attempting to read from the DB"); - } - } finally { - if (listener != null) { - dbRef.removeEventListener(listener); - } + // Returns null on timeout. + Boolean isSuccess = resultObtained.poll(timeout.value, timeout.units); + + // null will be returned on read timeout. + if (isSuccess == null) { + infofmt("Read from %s timed out after %d %s", path, timeout.value, timeout.units); + throw new Exception( + "Firebase Database read operation from '" + + path + + "' timed out after " + + timeout.value + + " " + + timeout.units.toString()); + } else if (!isSuccess) { + throw new Exception("Error occurred attempting to read from the DB"); } return obtainedValue.get(0); diff --git a/src/agent/internals/src/test/java/com/google/devtools/cdbg/debuglets/java/FirebaseClientTest.java b/src/agent/internals/src/test/java/com/google/devtools/cdbg/debuglets/java/FirebaseClientTest.java index 58cbcb62..a90578ef 100644 --- a/src/agent/internals/src/test/java/com/google/devtools/cdbg/debuglets/java/FirebaseClientTest.java +++ b/src/agent/internals/src/test/java/com/google/devtools/cdbg/debuglets/java/FirebaseClientTest.java @@ -23,6 +23,7 @@ import static org.mockito.ArgumentMatchers.eq; import static org.mockito.ArgumentMatchers.notNull; import static org.mockito.ArgumentMatchers.startsWith; +import static org.mockito.Mockito.atLeast; import static org.mockito.Mockito.doAnswer; import static org.mockito.Mockito.doReturn; import static org.mockito.Mockito.inOrder; @@ -53,6 +54,7 @@ import java.io.PrintWriter; import java.io.UnsupportedEncodingException; import java.security.NoSuchAlgorithmException; +import java.time.Duration; import java.util.ArrayList; import java.util.Arrays; import java.util.HashSet; @@ -104,8 +106,11 @@ public final class FirebaseClientTest { private FirebaseClient.TimeoutConfig timeouts = new FirebaseClient.TimeoutConfig(100, TimeUnit.MILLISECONDS); - private MetadataQuery metadata; + // Set the default high, we don't want it interfering with most tests. Tests that care about the + // functionality will use their own value. + private Duration markDebuggeeActivePeriod = Duration.ofHours(1); + private MetadataQuery metadata; private ClassPathLookup classPathLookup = new ClassPathLookup(false, null); /** @@ -194,7 +199,12 @@ public void initializeFirebaseAppSuccessOnDefaultRtdbInstance() throws Exception FirebaseClient firebaseClient = new FirebaseClient( - metadata, classPathLookup, DEFAULT_LABELS, mockFirebaseStaticWrappers, timeouts); + metadata, + classPathLookup, + DEFAULT_LABELS, + mockFirebaseStaticWrappers, + timeouts, + markDebuggeeActivePeriod); firebaseClient.initializeFirebaseApp(); ArgumentCaptor capturedFirebaseOptions = @@ -243,7 +253,12 @@ public void initializeFirebaseAppThrowsOnFailure() throws Exception { FirebaseClient firebaseClient = new FirebaseClient( - metadata, classPathLookup, DEFAULT_LABELS, mockFirebaseStaticWrappers, timeouts); + metadata, + classPathLookup, + DEFAULT_LABELS, + mockFirebaseStaticWrappers, + timeouts, + markDebuggeeActivePeriod); Exception ex = assertThrows(Exception.class, () -> firebaseClient.initializeFirebaseApp()); assertThat(ex) .hasMessageThat() @@ -277,6 +292,8 @@ public void registerDebuggeeSuccess() throws Exception { assertThat(registeredDebuggee.labels).containsEntry("module", "default"); assertThat(registeredDebuggee.labels).containsEntry("version", "v1"); assertThat(registeredDebuggee.labels).containsEntry("minorversion", "12345"); + assertThat(registeredDebuggee.registrationTimeMsec).containsEntry(".sv", "timestamp"); + assertThat(registeredDebuggee.lastUpdateTimeMsec).containsEntry(".sv", "timestamp"); assertThat(registeredDebuggee.agentVersion).matches("cloud-debug-java/v[0-9]+.[0-9]+"); assertThat(registeredDebuggee.sourceContexts).isEmpty(); } @@ -288,7 +305,7 @@ public void registerDebuggeeWithExtraLabels() throws Exception { ImmutableMap extraLabels = ImmutableMap.of("afoo", "abar", "mkfoo", "mkbar", "sfoo", "sbar"); - registerDebuggee(DEFAULT_LABELS, extraLabels); + registerDebuggee(DEFAULT_LABELS, extraLabels, markDebuggeeActivePeriod); assertThat(registeredDebuggee.id).matches("d-[0-9a-f]{8,8}"); assertThat(registeredDebuggee.uniquifier).matches("[0-9A-F]+"); assertThat(registeredDebuggee.description).isEqualTo("mock-project-id-default-v1-12345"); @@ -299,6 +316,8 @@ public void registerDebuggeeWithExtraLabels() throws Exception { assertThat(registeredDebuggee.labels).containsEntry("afoo", "abar"); assertThat(registeredDebuggee.labels).containsEntry("mkfoo", "mkbar"); assertThat(registeredDebuggee.labels).containsEntry("sfoo", "sbar"); + assertThat(registeredDebuggee.registrationTimeMsec).containsEntry(".sv", "timestamp"); + assertThat(registeredDebuggee.lastUpdateTimeMsec).containsEntry(".sv", "timestamp"); assertThat(registeredDebuggee.agentVersion).matches("cloud-debug-java/v[0-9]+.[0-9]+"); assertThat(registeredDebuggee.sourceContexts).isEmpty(); } @@ -331,7 +350,7 @@ public void registerDebuggeeDescription() throws Exception { .buildOrThrow(); for (Entry, String> testCase : testCases.entrySet()) { - registerDebuggee(testCase.getKey(), EMPTY_EXTRA_DEBUGGEE_LABELS); + registerDebuggee(testCase.getKey(), EMPTY_EXTRA_DEBUGGEE_LABELS, markDebuggeeActivePeriod); assertThat(registeredDebuggee.description).isEqualTo(testCase.getValue()); } } @@ -403,7 +422,12 @@ public void registerDebuggeeThrowsOnInitializeFirebaseAppFailure() throws Except FirebaseClient firebaseClient = new FirebaseClient( - metadata, classPathLookup, DEFAULT_LABELS, mockFirebaseStaticWrappers, timeouts); + metadata, + classPathLookup, + DEFAULT_LABELS, + mockFirebaseStaticWrappers, + timeouts, + markDebuggeeActivePeriod); Exception ex = assertThrows( Exception.class, () -> firebaseClient.registerDebuggee(EMPTY_EXTRA_DEBUGGEE_LABELS)); @@ -415,6 +439,141 @@ public void registerDebuggeeThrowsOnInitializeFirebaseAppFailure() throws Except + " https://mock-project-id-default-rtdb.firebaseio.com]"); } + @Test + public void registerDebuggeeWorksAsExpectedWhenAlreadyInRtdb() throws Exception { + DatabaseReference mockSchemaVersionDbRef = mock(DatabaseReference.class); + DatabaseReference mockDebuggeesDbRef = mock(DatabaseReference.class); + DatabaseReference mockBreakpointsDbRef = mock(DatabaseReference.class); + + when(mockFirebaseStaticWrappers.getDbInstance(mockFirebaseApp)) + .thenReturn(mockFirebaseDatabase); + when(mockFirebaseDatabase.getReference(eq("cdbg/schema_version"))) + .thenReturn(mockSchemaVersionDbRef); + when(mockFirebaseDatabase.getReference(startsWith("cdbg/debuggees"))) + .thenReturn(mockDebuggeesDbRef); + when(mockFirebaseDatabase.getReference(startsWith("cdbg/breakpoints/"))) + .thenReturn(mockBreakpointsDbRef); + + ArgumentCaptor capturedDebuggee = ArgumentCaptor.forClass(Object.class); + ArgumentCaptor capturedDbPaths = ArgumentCaptor.forClass(String.class); + ArgumentCaptor capturedBpUpdateListener = + ArgumentCaptor.forClass(ValueEventListener.class); + + setResponseDbGet(mockSchemaVersionDbRef, "2"); + + // registerDebuggee will test if the Debuggee exists yet in the DB, returning a value here + // indicates it does exist, and the registration code won't write out the full Debuggee, but + // rather simply update the lastUpdateTimeMsec field. + setResponseDbGet(mockDebuggeesDbRef, "1669841300081"); + + // This will be for the udpate to lastActiveTimeMsec + setCompletionSuccessDbSet(mockDebuggeesDbRef); + + FirebaseClient firebaseClient = + new FirebaseClient( + metadata, + classPathLookup, + DEFAULT_LABELS, + mockFirebaseStaticWrappers, + timeouts, + markDebuggeeActivePeriod); + assertThat(firebaseClient.registerDebuggee(EMPTY_EXTRA_DEBUGGEE_LABELS)).isTrue(); + verify(mockDebuggeesDbRef).setValue(capturedDebuggee.capture(), any()); + + verify(mockFirebaseDatabase, times(4)).getReference(capturedDbPaths.capture()); + List dbPaths = capturedDbPaths.getAllValues(); + assertThat(dbPaths) + .isEqualTo( + Arrays.asList( + "cdbg/schema_version", + String.format( + "cdbg/debuggees/%s/registrationTimeMsec", firebaseClient.getDebuggeeId()), + String.format( + "cdbg/debuggees/%s/lastUpdateTimeMsec", firebaseClient.getDebuggeeId()), + String.format("cdbg/breakpoints/%s/active", firebaseClient.getDebuggeeId()))); + + verify(mockBreakpointsDbRef).addValueEventListener(capturedBpUpdateListener.capture()); + this.breakpointUpdateListener = capturedBpUpdateListener.getValue(); + assertThat(this.breakpointUpdateListener).isNotNull(); + + reset(mockFirebaseDatabase); + } + + @Test + public void registerDebuggeeThrowsOnGetDebuggeeRegistrationTimeTimeout() throws Exception { + DatabaseReference mockSchemaVersionDbRef = mock(DatabaseReference.class); + DatabaseReference mockDebuggeesDbRef = mock(DatabaseReference.class); + + when(mockFirebaseStaticWrappers.getDbInstance(mockFirebaseApp)) + .thenReturn(mockFirebaseDatabase); + when(mockFirebaseDatabase.getReference(eq("cdbg/schema_version"))) + .thenReturn(mockSchemaVersionDbRef); + when(mockFirebaseDatabase.getReference(startsWith("cdbg/debuggees/"))) + .thenReturn(mockDebuggeesDbRef); + + setResponseDbGet(mockSchemaVersionDbRef, "2"); + + // NOTE, we don't set a response for the debuggee registration time get call, so it will + // timeout. + + FirebaseClient firebaseClient = + new FirebaseClient( + metadata, + classPathLookup, + DEFAULT_LABELS, + mockFirebaseStaticWrappers, + timeouts, + markDebuggeeActivePeriod); + Exception ex = + assertThrows( + Exception.class, () -> firebaseClient.registerDebuggee(EMPTY_EXTRA_DEBUGGEE_LABELS)); + assertThat(ex) + .hasMessageThat() + .matches( + "Firebase Database read operation from 'cdbg/debuggees/.*/registrationTimeMsec' timed" + + " out after.*"); + } + + @Test + public void registerDebuggeeThrowsOnSetDebuggeeLastUpdateTimeTimeout() throws Exception { + DatabaseReference mockSchemaVersionDbRef = mock(DatabaseReference.class); + DatabaseReference mockDebuggeesDbRef = mock(DatabaseReference.class); + + when(mockFirebaseStaticWrappers.getDbInstance(mockFirebaseApp)) + .thenReturn(mockFirebaseDatabase); + when(mockFirebaseDatabase.getReference(eq("cdbg/schema_version"))) + .thenReturn(mockSchemaVersionDbRef); + when(mockFirebaseDatabase.getReference(startsWith("cdbg/debuggees/"))) + .thenReturn(mockDebuggeesDbRef); + + setResponseDbGet(mockSchemaVersionDbRef, "2"); + + // registerDebuggee will test if the Debuggee exists yet in the DB, returning a value here + // indicates it does exist, and the registration code won't write out the full Debuggee, but + // rather simply update the lastUpdateTimeMsec field. + setResponseDbGet(mockDebuggeesDbRef, "1669841300081"); + + // NOTE, don't set a set completion response for the last update write, this will cause the set + // to timeout as desired by the test. + + FirebaseClient firebaseClient = + new FirebaseClient( + metadata, + classPathLookup, + DEFAULT_LABELS, + mockFirebaseStaticWrappers, + timeouts, + markDebuggeeActivePeriod); + Exception ex = + assertThrows( + Exception.class, () -> firebaseClient.registerDebuggee(EMPTY_EXTRA_DEBUGGEE_LABELS)); + assertThat(ex) + .hasMessageThat() + .matches( + "Firebase Database write operation to 'cdbg/debuggees.*/lastUpdateTimeMsec' failed," + + " error: 'Timed out after.*'"); + } + @Test public void registerDebuggeeThrowsOnSetDebuggeeTimeout() throws Exception { DatabaseReference mockSchemaVersionDbRef = mock(DatabaseReference.class); @@ -428,19 +587,29 @@ public void registerDebuggeeThrowsOnSetDebuggeeTimeout() throws Exception { .thenReturn(mockDebuggeesDbRef); setResponseDbGet(mockSchemaVersionDbRef, "2"); - // NOTE, don't set a response for the debuggees reference, this will cause the set to timeout as - // desired by the test. + + // For the registrationTimeMsec check, returning null here indicates it does not yet exist + setResponseDbGet(mockDebuggeesDbRef, null); + + // NOTE, don't set a set completion response for the debuggees reference, this will cause the + // set to timeout as desired by the test. FirebaseClient firebaseClient = new FirebaseClient( - metadata, classPathLookup, DEFAULT_LABELS, mockFirebaseStaticWrappers, timeouts); + metadata, + classPathLookup, + DEFAULT_LABELS, + mockFirebaseStaticWrappers, + timeouts, + markDebuggeeActivePeriod); Exception ex = assertThrows( Exception.class, () -> firebaseClient.registerDebuggee(EMPTY_EXTRA_DEBUGGEE_LABELS)); assertThat(ex) .hasMessageThat() .matches( - "Firebase Database write operation to 'cdbg/debuggees.* error: 'Timed out after.*'"); + "Firebase Database write operation to 'cdbg/debuggees.*' failed, error: 'Timed out" + + " after.*'"); } @Test @@ -456,11 +625,20 @@ public void registerDebuggeeThrowsOnSetDebuggeeError() throws Exception { .thenReturn(mockDebuggeesDbRef); setResponseDbGet(mockSchemaVersionDbRef, "2"); + + // For the registrationTimeMsec check, returning null here indicates it does not yet exist + setResponseDbGet(mockDebuggeesDbRef, null); + setCompletionFailedDbSet(mockDebuggeesDbRef, "FAKE DB ERROR"); FirebaseClient firebaseClient = new FirebaseClient( - metadata, classPathLookup, DEFAULT_LABELS, mockFirebaseStaticWrappers, timeouts); + metadata, + classPathLookup, + DEFAULT_LABELS, + mockFirebaseStaticWrappers, + timeouts, + markDebuggeeActivePeriod); Exception ex = assertThrows( Exception.class, () -> firebaseClient.registerDebuggee(EMPTY_EXTRA_DEBUGGEE_LABELS)); @@ -893,6 +1071,82 @@ public void transmitBreakpointUpdateModificationsCached() throws Exception { verify(mockFinalDbRef).setValue(eq(expectedFinalBpObject), any()); } + @Test + public void markDebuggeeActiveWorksAsExpected() throws Exception { + Duration updatePeriod = Duration.ofMillis(100); + FirebaseClient client = registerDebuggee(updatePeriod); + + String lastUpdateTimeDbPath = + String.format("cdbg/debuggees/%s/lastUpdateTimeMsec", client.getDebuggeeId()); + DatabaseReference mockDebuggeeLastUpdateTimeDbRef = mock(DatabaseReference.class); + when(mockFirebaseDatabase.getReference(eq(lastUpdateTimeDbPath))) + .thenReturn(mockDebuggeeLastUpdateTimeDbRef); + + setCompletionSuccessDbSet(mockDebuggeeLastUpdateTimeDbRef); + + TimeUnit.SECONDS.sleep(1); + verify(mockDebuggeeLastUpdateTimeDbRef, atLeast(3)) + .setValue(eq(ImmutableMap.of(".sv", "timestamp")), any()); + } + + @Test + public void periodicMarkDebuggeeActiveFailureWorksAsExpected() throws Exception { + // If a failure occurs on a periodic mark debuggee active attempt, the agent will re-register. + // This means the next call to listActiveBreakpoints should fail to force a reregister of the + // debuggee. During this time there should be no attempts to periodically mark the debuggee + // active. + Duration updatePeriod = Duration.ofMillis(100); + FirebaseClient client = registerDebuggee(updatePeriod); + + String lastUpdateTimeDbPath = + String.format("cdbg/debuggees/%s/lastUpdateTimeMsec", client.getDebuggeeId()); + DatabaseReference mockDebuggeeLastUpdateTimeDbRef = mock(DatabaseReference.class); + when(mockFirebaseDatabase.getReference(eq(lastUpdateTimeDbPath))) + .thenReturn(mockDebuggeeLastUpdateTimeDbRef); + + setCompletionFailedDbSet(mockDebuggeeLastUpdateTimeDbRef, "FAKE DB ERROR"); + TimeUnit.SECONDS.sleep(1); + + assertThrows(Exception.class, () -> client.listActiveBreakpoints()); + + // There should be only 1 attempt, the one that failed. Unitl the re-register, no further + // attempts should be made. + verify(mockDebuggeeLastUpdateTimeDbRef, times(1)) + .setValue(eq(ImmutableMap.of(".sv", "timestamp")), any()); + + // As a final step, we'll re-regster and ensure the periodic mark debuggee active continues. + reset(mockFirebaseDatabase); + DatabaseReference mockDebuggeesDbRef = mock(DatabaseReference.class); + DatabaseReference mockBreakpointsDbRef = mock(DatabaseReference.class); + when(mockFirebaseStaticWrappers.getDbInstance(mockFirebaseApp)) + .thenReturn(mockFirebaseDatabase); + when(mockFirebaseDatabase.getReference(startsWith("cdbg/debuggees/"))) + .thenReturn(mockDebuggeesDbRef); + when(mockFirebaseDatabase.getReference(startsWith("cdbg/breakpoints/"))) + .thenReturn(mockBreakpointsDbRef); + + // registerDebuggee will test if the Debuggee exists yet in the DB, returning a value here + // indicates it does exist, and the registration code won't write out the full Debuggee, but + // rather simply update the lastUpdateTimeMsec field. + setResponseDbGet(mockDebuggeesDbRef, "1669841300081"); + + // For the setting of the debuggee in the RTDB + setCompletionSuccessDbSet(mockDebuggeesDbRef); + + assertThat(client.registerDebuggee(EMPTY_EXTRA_DEBUGGEE_LABELS)).isTrue(); + + // Now verify that periodic updates have restarted. + reset(mockFirebaseDatabase); + reset(mockDebuggeeLastUpdateTimeDbRef); + setCompletionSuccessDbSet(mockDebuggeeLastUpdateTimeDbRef); + when(mockFirebaseDatabase.getReference(eq(lastUpdateTimeDbPath))) + .thenReturn(mockDebuggeeLastUpdateTimeDbRef); + + TimeUnit.SECONDS.sleep(1); + verify(mockDebuggeeLastUpdateTimeDbRef, atLeast(3)) + .setValue(eq(ImmutableMap.of(".sv", "timestamp")), any()); + } + @Test public void computeDebuggeeIdWorksAsExpected() throws NoSuchAlgorithmException { FirebaseClient.Debuggee debuggee = new FirebaseClient.Debuggee(); @@ -902,7 +1156,12 @@ public void computeDebuggeeIdWorksAsExpected() throws NoSuchAlgorithmException { // get an instance of the client. FirebaseClient firebaseClient = new FirebaseClient( - metadata, classPathLookup, DEFAULT_LABELS, mockFirebaseStaticWrappers, timeouts); + metadata, + classPathLookup, + DEFAULT_LABELS, + mockFirebaseStaticWrappers, + timeouts, + markDebuggeeActivePeriod); ImmutableMap labels1 = ImmutableMap.builder() @@ -990,7 +1249,13 @@ public void dbListenerFailureWorksAsExpected() throws Exception { .thenReturn(mockDebuggeesDbRef); when(mockFirebaseDatabase.getReference(startsWith("cdbg/breakpoints/"))) .thenReturn(mockBreakpointsDbRef); + + // This is the test to the debuggee registrationTimeMsec, indicates Debuggee not yet in RTDB + setResponseDbGet(mockDebuggeesDbRef, null); + + // For the setting of the debuggee in the RTDB setCompletionSuccessDbSet(mockDebuggeesDbRef); + assertThat(hubClient.registerDebuggee(EMPTY_EXTRA_DEBUGGEE_LABELS)).isTrue(); // Now listActiveBreakpoints() should succeed again. @@ -999,15 +1264,26 @@ public void dbListenerFailureWorksAsExpected() throws Exception { /** Common code to get the debuggee registered for all test cases requiring that. */ private FirebaseClient registerDebuggee() throws Exception { - return registerDebuggee(DEFAULT_LABELS, EMPTY_EXTRA_DEBUGGEE_LABELS); + return registerDebuggee(DEFAULT_LABELS, EMPTY_EXTRA_DEBUGGEE_LABELS, markDebuggeeActivePeriod); + } + + /** Common code to get the debuggee registered with custom markDebuggeeActive period. */ + private FirebaseClient registerDebuggee(Duration markDebuggeeActivePeriod) throws Exception { + return registerDebuggee(DEFAULT_LABELS, EMPTY_EXTRA_DEBUGGEE_LABELS, markDebuggeeActivePeriod); } /** * Common code to get the debuggee registered with extra labels provided in the registerDebuggee * call. + * + *

To note, this goes through what it considers the 'common' path of the Debuggee not being + * present in the RTDB yet and the debuggee having to be written to it. */ private FirebaseClient registerDebuggee( - Map gcpEnvironmentLabels, Map extraLabels) throws Exception { + Map gcpEnvironmentLabels, + Map extraLabels, + Duration markDebuggeeActivePeriod) + throws Exception { DatabaseReference mockSchemaVersionDbRef = mock(DatabaseReference.class); DatabaseReference mockDebuggeesDbRef = mock(DatabaseReference.class); @@ -1017,7 +1293,7 @@ private FirebaseClient registerDebuggee( .thenReturn(mockFirebaseDatabase); when(mockFirebaseDatabase.getReference(eq("cdbg/schema_version"))) .thenReturn(mockSchemaVersionDbRef); - when(mockFirebaseDatabase.getReference(startsWith("cdbg/debuggees/"))) + when(mockFirebaseDatabase.getReference(startsWith("cdbg/debuggees"))) .thenReturn(mockDebuggeesDbRef); when(mockFirebaseDatabase.getReference(startsWith("cdbg/breakpoints/"))) .thenReturn(mockBreakpointsDbRef); @@ -1028,21 +1304,34 @@ private FirebaseClient registerDebuggee( ArgumentCaptor.forClass(ValueEventListener.class); setResponseDbGet(mockSchemaVersionDbRef, "2"); + + // registerDebuggee will test if the Debuggee exists yet in the DB, returning null here + // indicates it does not yet exist. + setResponseDbGet(mockDebuggeesDbRef, null); + + // This will be registerDebuggee setting the Debuggee in the RTDB since we returned null + // when it tested if the debuggee existed. setCompletionSuccessDbSet(mockDebuggeesDbRef); FirebaseClient firebaseClient = new FirebaseClient( - metadata, classPathLookup, gcpEnvironmentLabels, mockFirebaseStaticWrappers, timeouts); + metadata, + classPathLookup, + gcpEnvironmentLabels, + mockFirebaseStaticWrappers, + timeouts, + markDebuggeeActivePeriod); assertThat(firebaseClient.registerDebuggee(extraLabels)).isTrue(); verify(mockDebuggeesDbRef).setValue(capturedDebuggee.capture(), any()); this.registeredDebuggee = (FirebaseClient.Debuggee) capturedDebuggee.getValue(); - verify(mockFirebaseDatabase, times(3)).getReference(capturedDbPaths.capture()); + verify(mockFirebaseDatabase, times(4)).getReference(capturedDbPaths.capture()); List dbPaths = capturedDbPaths.getAllValues(); assertThat(dbPaths) .isEqualTo( Arrays.asList( "cdbg/schema_version", + String.format("cdbg/debuggees/%s/registrationTimeMsec", registeredDebuggee.id), String.format("cdbg/debuggees/%s", registeredDebuggee.id), String.format("cdbg/breakpoints/%s/active", registeredDebuggee.id))); @@ -1136,7 +1425,7 @@ public Void answer(InvocationOnMock invocation) { } }) .when(mockDbRef) - .addValueEventListener((ValueEventListener) notNull()); + .addListenerForSingleValueEvent((ValueEventListener) notNull()); } private void setOnCancelledDbGet(DatabaseReference mockDbRef, String errorMessage) {