launchdarkly / react-client-sdk

LaunchDarkly Client-side SDK for React.js
Other
86 stars 70 forks source link

Incorrect flag values returned from `useFlags` after rapid calls to `identify` #220

Open michaelowolf opened 1 year ago

michaelowolf commented 1 year ago

Describe the bug

When identify is called repeatedly after initialisation, it seems that incorrect (probably out of date) flag values are eventually returned by useFlags.

To reproduce

  1. Set up a component that accesses flags using the useFlags hook
  2. Initialise the LD provider using asyncWithLDProvider with a context that will return a specific set of flag values (e.g. an anonymous user context)
  3. Trigger an effect in a component that calls identify with the same context again
  4. Trigger the same effect with a new context that should result in a different set of flag values (e.g. a non-anonymous user context)

In our case, when a signed-in user loads the page, we resume their session in parallel with initialising LaunchDarkly, meaning we initialise with an anonymous user context by default. We then have a bespoke hook that provides an updating reference to the currently signed-in user (if any), which triggers an effect that calls identify with the corresponding LD context.

While resuming their session, this results in a call to identify with an anonymous user context (since effects always run initially), then switches to a non-anonymous user context once the session is resumed.

These calls can occur in quick succession, and the result seems to be that we end up with stale or incorrect flag values.

I'm reproducing it with (effectively) this code:

// FeatureFlagsProvider.tsx
import { asyncWithLDProvider, useLDClient, useFlags } from 'launchdarkly-react-client-sdk';
import { useEffect, useMemo } from 'react';

const defaultContext = { kind: 'user', anonymous: true };

console.log('[LaunchDarkly] Awaiting async provider');

const LDProvider = await asyncWithLDProvider({
    clientSideID: '...',
    context: defaultContext,
    options: {
        streaming: true,
        application: { ... },
        sendEvents: false,
        fetchGoals: false,
    },
});

console.log('[LaunchDarkly] Async provider done');

const LDIdentifier = ({ children }) => {
    const ldClient = useLDClient();

    // Some updating reference to a value that influences the LD context
    const currentUser = useCurrentUser();

    const context = useMemo(
        () =>
            currentUser?.id
                ? { kind: 'user', key: `${currentUser.id}` }
                : defaultContext,
        [currentUser],
    );

    useEffect(() => {
        if (!ldClient) {
            return;
        }

        console.log('[LaunchDarkly] Identifying with context', JSON.stringify(context));
        ldClient.identify(context);
    }, [ldClient, context]);

    const flags = useFlags();

    useEffect(() => {
        console.log('[LaunchDarkly] Got flags', JSON.stringify(flags));
    }, [flags]);

    return children;
};

// Rendered as a provider for the app
export function FeatureFlagsProvider({ children }) {
    return (
        <LDProvider>
            <LDIdentifier>{children}</LDIdentifier>
        </LDProvider>
    );
}

Expected behavior

The last set of flag values returned correspond to the last context identified with.

Logs

Logs from the above code:

FeatureFlagsProvider.tsx [LaunchDarkly] Awaiting async provider
ldclient.es.js:1 [LaunchDarkly] LaunchDarkly client initialized
ldclient.es.js:1 [LaunchDarkly] Opening stream connection to [...]
FeatureFlagsProvider.tsx [LaunchDarkly] Async provider done
FeatureFlagsProvider.tsx [LaunchDarkly] Identifying with context {"kind":"user","anonymous":true}
FeatureFlagsProvider.tsx [LaunchDarkly] Got flags {"featureFlagDemo":false}
FeatureFlagsProvider.tsx [LaunchDarkly] Identifying with context {"kind":"user","key":"..."}
ldclient.es.js:1 [LaunchDarkly] Closing stream connection
ldclient.es.js:1 [LaunchDarkly] Opening stream connection to [...]
ldclient.es.js:1 [LaunchDarkly] Closing stream connection
ldclient.es.js:1 [LaunchDarkly] Opening stream connection to [...]
FeatureFlagsProvider.tsx [LaunchDarkly] Got flags {"featureFlagDemo":false}

Corresponding network requests:

GET https://app.launchdarkly.com/sdk/evalx/.../contexts/... => Response {
    "feature-flag-demo": {
        "flagVersion": 55,
        "trackEvents": false,
        "value": false,
        "variation": 1,
        "version": 62
    }
}
GET https://clientstream.launchdarkly.com/eval/.../... => EventStream [
    [put, {"feature-flag-demo":{"version":62,"flagVersion":55,"value":false,"variation":1,"trackEvents":false}}]
]
GET https://app.launchdarkly.com/sdk/evalx/.../contexts/... => Response {
    "feature-flag-demo": {
        "flagVersion": 55,
        "trackEvents": false,
        "value": true,
        "variation": 0,
        "version": 62
    }
}
GET https://app.launchdarkly.com/sdk/evalx/.../contexts/... => Response {
    "feature-flag-demo": {
        "flagVersion": 55,
        "trackEvents": false,
        "value": false,
        "variation": 1,
        "version": 62
    }
}
GET https://clientstream.launchdarkly.com/eval/.../... => EventStream [
    [put, {"feature-flag-demo":{"version":62,"flagVersion":55,"value":false,"variation":1,"trackEvents":false}}]
]

SDK version

6.0.9

OS/platform

macOS Monterey 12.6.7 (21G651)

Brave Version 1.56.20 Chromium: 115.0.5790.171 (Official Build) (x86_64) Chrome Version 117.0.5938.92 (Official Build) (x86_64) Safari Version 16.5.2 (17615.2.9.101.1, 17615)

Additional context

I expect there's a good chance that this is an issue with the JS SDK or JS common SDK rather than the React SDK, but I couldn't see anything that looked related in their issues and I don't have a strong enough understanding of the innards of the SDKs to say one way or another, so I'm raising it here as a first port of call .

I'd guess it's a timing issue, as occasionally the correct flag values are returned, and this seems to be affected by page load time too. I suspect the initialisation call works as expected but the repeated calls to identify are the cause. Looking at the network requests, it seems a call to identify (having enabled streaming) results in both a GET of the flag values plus opening an EventStream which then sends a message with the flag values too, so maybe these responses & messages are interleaving with the repeated calls in a way that isn't handled correctly.

It's entirely possible we're doing something incorrect in the way we're using the SDK, and I appreciate it could be mitigated by stricter management of the calls to identify. I've been able to work around the issue by storing a reference to the identify promise, and chaining any new calls off that (which is a little clunky):

    const identifyPromise = useRef();

    useEffect(() => {
        identifyPromise.current = identifyPromise.current
            ? identifyPromise.current.finally(() => ldClient.identify(context))
            : ldClient.identify(context);
    }, [ldClient, context]);

It occurs with and without StrictMode.

yusinto commented 1 year ago

Thank you for the detailed report. In order to assist in debugging, I spent time to simplify your sample code to bare minimum. Please see my simplified code here. Points to note:

michaelowolf commented 1 year ago

Hey @yusinto, thanks for your response.

I might have caused confusion with my reproduction code, because the portion where useFlags is called and the flags are logged was supposed to exemplify a separate child component, where we would actually want to use the flags to control a feature:

// SomeFeatureComponent.tsx
export function SomeFeatureComponent() {
  const flags = useFlags();

  useEffect(() => {
      console.log('[LaunchDarkly] Got flags', JSON.stringify(flags));
  }, [flags]);

  return flags.someFeature ? (<>...<>) : undefined;
}

As a result, I'm not sure awaiting the identify call and then making a call to ldClient.allFlags() in a single execution of the effect gives a fair representation of the issue.

Even so, as I'm sure you're aware, awaiting the call does not mean the separate executions of the effect will await each other to run in sequence. Admittedly the timing seems to be better in your version, which makes the issue a little harder to reproduce, until I add a third call by running in React's StrictMode:

FeatureFlagsProvider.tsx [LaunchDarkly] Awaiting async provider
ldclient.es.js:1 [LaunchDarkly] LaunchDarkly client initialized
ldclient.es.js:1 [LaunchDarkly] Opening stream connection to [...]
FeatureFlagsProvider.tsx [LaunchDarkly] Async provider done
FeatureFlagsProvider.tsx [LaunchDarkly] Identifying with context (call 1) {"kind":"user","anonymous":true}
FeatureFlagsProvider.tsx [LaunchDarkly] Got flags {"featureFlagDemo":false}
FeatureFlagsProvider.tsx [LaunchDarkly] Identifying with context (call 2) {"kind":"user","anonymous":true}
FeatureFlagsProvider.tsx [LaunchDarkly] Got flags {"featureFlagDemo":false}
FeatureFlagsProvider.tsx [LaunchDarkly] Identifying with context (call 3) {"kind":"user","key":"..."}
ldclient.es.js:1 [LaunchDarkly] Closing stream connection
ldclient.es.js:1 [LaunchDarkly] Opening stream connection to [...]
FeatureFlagsProvider.tsx [LaunchDarkly] For context (call 3): {"kind":"user","key":"..."}, flags: {"feature-flag-demo":true}
FeatureFlagsProvider.tsx [LaunchDarkly] Got flags {"featureFlagDemo":true}
ldclient.es.js:1 [LaunchDarkly] Closing stream connection
ldclient.es.js:1 [LaunchDarkly] Opening stream connection to [...]
ldclient.es.js:1 [LaunchDarkly] Closing stream connection
ldclient.es.js:1 [LaunchDarkly] Opening stream connection to [...]
FeatureFlagsProvider.tsx [LaunchDarkly] For context (call 1) {"kind":"user","anonymous":true}, flags: {"feature-flag-demo":false}
FeatureFlagsProvider.tsx [LaunchDarkly] For context (call 2) {"kind":"user","anonymous":true}, flags: {"feature-flag-demo":false}
FeatureFlagsProvider.tsx [LaunchDarkly] Got flags {"featureFlagDemo":false}

As suggested by my original workaround, it seems that each call to identify must be resolved before another is made when using useFlags. (And as a result, I also don't think typical React data fetching techniques to ignore earlier responses when they are superseded by later calls could help specifically with useFlags.)

michaelowolf commented 10 months ago

Hey @yusinto, although we have a workaround for this issue, I thought I'd create a minimal reproduction to in case it's still worth investigating on your side.

I've created a repo at https://github.com/michaelowolf/launch-darkly-wrong-flags which can reproduce the issue. I've just used create-react-app, so it can be ran with npm start. You'll need to enter an LD client id where the provider is instantiated, and may need to modify the useSignedInUser hook to ensure the signed-in user context gets different flag values to the signed-out user context (depending on your LD setup). After that, a few refreshes normally triggers the issue for me.

I've also added some log extracts to that repo in the logs folder, that shows both the working and non-working cases. It seems the calls to identify can resolve in different orders (which explains why our workaround works).

I also never followed up on this, but you mentioned avoiding breaking the rules of hooks. Could you clarify what rules are being broken?