Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[GC] Update a GC end-to-end test to use sinon timers instead of real ones #23516

Open
wants to merge 3 commits into
base: main
Choose a base branch
from

Conversation

agarwal-navin
Copy link
Contributor

@agarwal-navin agarwal-navin commented Jan 8, 2025

This PR updates one of the GC end-to-end test to use sinon fake timers instead of real timers. The tests in this file adds delays to wait for sweep timers to expire. Using fake timers these delays have been replaced with advancing the clock thereby reducing the runtime.
The run time for this test file went from 4s to 2s.

AB#11248

@github-actions github-actions bot added area: tests Tests to add, test infrastructure improvements, etc base: main PRs targeted against main branch labels Jan 8, 2025
Copy link
Contributor

@Copilot Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Copilot reviewed 1 out of 1 changed files in this pull request and generated 1 comment.

Comments suppressed due to low confidence (1)

packages/test/test-end-to-end-tests/src/test/gc/gcSweepDataStores.spec.ts:685

  • Replace 'tombstone ready' with 'sweep ready' for consistency.
// Summarize. The tombstone ready data store should get realized because it has a trailing op.

{
eventName: "fluid:telemetry:Summarizer:Running:SweepReadyObject_Realized",
id: { value: `/${unreferencedId}`, tag: TelemetryDataTag.CodeArtifact },
eventName:
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The workaround to avoid this was to close the container that created the data store being deleted. However, on removing the delays, the test failied and I realized that closing the container causes the trailing op it sent to be not picked up by the LoaderContainerTracker. So, when the next summary happens, ensureSynchronized does not wait for the trailing op.

This should not have worked before this change either but for some reason it does maybe due to the awaits. My theory is that the op is likely processed by the summarizer by the time ensureSynchronized is called.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So, in this change I removed closing the container and added this itExpects. I think we can remove logging the GC_Deleted_DataStore_Unexpected_Delete error.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you have added a flush to the outbound queue or something? Like provider.processOutgoing? That waits for all ops to be sequenced and received (but not processed) by all tracked containers.

Also, I don't think we should remove that log. It's an important assumption that we should protect, so it doesn't accidentally regress with any of the architectural changes that may come to the runtime in the next year+.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

While incorporating #23516 (comment), I used a workaround to not do this.

@@ -30,7 +30,6 @@ import {
import type { ISummarizeEventProps } from "@fluidframework/container-runtime-definitions/internal";
import { IErrorBase } from "@fluidframework/core-interfaces";
import { FluidErrorTypes } from "@fluidframework/core-interfaces/internal";
import { delay } from "@fluidframework/core-utils/internal";
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

nice!

@@ -400,7 +412,7 @@ describeCompat("GC data store sweep tests", "NoCompat", (getTestObjectProvider)
);

// Flush microtask queue to get PathInfo event logged
await delay(0);
await clock.tickAsync(0);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wouldn't assume this does anything, but if the tests pass maybe it does? Did you read about it or experiment at all?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think you want tickAsync?

    /**
     * Advance the clock, firing callbacks if necessary.
     *
     * @param time   How many ticks to advance by.
     * @returns Fake milliseconds since the unix epoch.
     */
    tick: (time: number | string) => number;

    /**
     * Advance the clock, firing callbacks if necessary.
     *
     * Also breaks the event loop, allowing any scheduled promise callbacks to execute _before_ running the timers.
     *
     * @param time   How many ticks to advance by.
     * @returns Fake milliseconds since the unix epoch.
     */
    tickAsync: (time: number | string) => Promise<number>;

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I did use tickAsync. Did you mean to say tick?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I did not experiment a lot, no. This worked so I just used it.

@@ -224,7 +224,8 @@ const summarizationWithUnreferencedDataStoreAfterTime = async () => {
url: toFluidHandleInternal(testDataObject.handle).absolutePath,
});
const summarizerDataObject = response.value as ITestDataObject;
await delay(sweepTimeoutMs + 10);

clock.tick(sweepTimeoutMs + 10);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We should be able to stop overriding the timeouts now, and just use the default values. I think that would be preferable if it works (and good to know why if it doesn't)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good point. I changed it to use the default values. I had to re-arrange some logic but it worked. Session expiry is what makes it harder but I worked around it.

@github-actions github-actions bot added the area: runtime Runtime related issues label Jan 13, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area: runtime Runtime related issues area: tests Tests to add, test infrastructure improvements, etc base: main PRs targeted against main branch
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants