amplify-js icon indicating copy to clipboard operation
amplify-js copied to clipboard

fetchAuthSession() returning `{"name":"Unknown","underlyingError":{}} `

Open walterholohan opened this issue 1 year ago • 25 comments
trafficstars

Before opening, please confirm:

JavaScript Framework

React Native

Amplify APIs

Authentication

Amplify Version

v6

Amplify Categories

auth

Backend

Other

Environment information

System:
    OS: macOS 14.5
    CPU: (10) arm64 Apple M1 Pro
    Memory: 86.14 MB / 16.00 GB
    Shell: 5.9 - /bin/zsh
  Binaries:
    Node: 18.19.1 - ~/.nvm/versions/node/v18.19.1/bin/node
    Yarn: 1.22.19 - /opt/homebrew/bin/yarn
    npm: 10.2.4 - ~/.nvm/versions/node/v18.19.1/bin/npm
    Watchman: 2024.01.22.00 - /opt/homebrew/bin/watchman
  Browsers:
    Chrome: 127.0.6533.119
    Safari: 17.5
  npmPackages:
    @apollo/client: 3.10.8 => 3.10.8 (3.10.4)
    @apollo/client/cache:  undefined ()
    @apollo/client/core:  undefined ()
    @apollo/client/dev:  undefined ()
    @apollo/client/errors:  undefined ()
    @apollo/client/link/batch:  undefined ()
    @apollo/client/link/batch-http:  undefined ()
    @apollo/client/link/context:  undefined ()
    @apollo/client/link/core:  undefined ()
    @apollo/client/link/error:  undefined ()
    @apollo/client/link/http:  undefined ()
    @apollo/client/link/persisted-queries:  undefined ()
    @apollo/client/link/remove-typename:  undefined ()
    @apollo/client/link/retry:  undefined ()
    @apollo/client/link/schema:  undefined ()
    @apollo/client/link/subscriptions:  undefined ()
    @apollo/client/link/utils:  undefined ()
    @apollo/client/link/ws:  undefined ()
    @apollo/client/react:  undefined ()
    @apollo/client/react/components:  undefined ()
    @apollo/client/react/context:  undefined ()
    @apollo/client/react/hoc:  undefined ()
    @apollo/client/react/hooks:  undefined ()
    @apollo/client/react/internal:  undefined ()
    @apollo/client/react/parser:  undefined ()
    @apollo/client/react/ssr:  undefined ()
    @apollo/client/testing:  undefined ()
    @apollo/client/testing/core:  undefined ()
    @apollo/client/testing/experimental:  undefined ()
    @apollo/client/utilities:  undefined ()
    @apollo/client/utilities/globals:  undefined ()
    @apollo/client/utilities/subscriptions/relay:  undefined ()
    @apollo/client/utilities/subscriptions/urql:  undefined ()
    @aws-amplify/react-native: 1.1.4 => 1.1.4 
    @aws-amplify/rtn-web-browser: 1.0.31 => 1.0.31 
    @babel/core: 7.20.12 => 7.20.12 (7.22.8, 7.23.0)
    @babel/preset-env: 7.21.5 => 7.21.5 (7.24.4)
    @babel/runtime: 7.20.0 => 7.20.0 (7.22.6)
    @commitlint/cli: 19.3.0 => 19.3.0 
    @commitlint/config-conventional: 19.2.2 => 19.2.2 
    @date-fns/utc: 1.2.0 => 1.2.0 
    @googlemaps/polyline-codec: 1.0.28 => 1.0.28 
    @gorhom/bottom-sheet: 4.6.1 => 4.6.1 
    @gorhom/portal: 1.0.14 => 1.0.14 
    @graphql-codegen/cli: 5.0.2 => 5.0.2 
    @graphql-codegen/fragment-matcher: 5.0.2 => 5.0.2 
    @graphql-codegen/introspection: 4.0.3 => 4.0.3 
    @graphql-codegen/named-operations-object: 3.1.0 => 3.1.0 
    @graphql-codegen/typescript: 4.0.9 => 4.0.9 
    @graphql-codegen/typescript-operations: 4.2.3 => 4.2.3 
    @graphql-codegen/typescript-react-apollo: 4.3.0 => 4.3.0 
    @intercom/intercom-react-native: 7.1.3 => 7.1.3 
    @iterable/react-native-sdk: 1.3.19 => 1.3.19 
    @kingstinct/react-native-healthkit: 8.2.0 => 8.2.0 
    @notifee/react-native: 7.8.2 => 7.8.2 
    @react-native-async-storage/async-storage: 1.24.0 => 1.24.0 
    @react-native-camera-roll/camera-roll: 7.8.1 => 7.8.1 
    @react-native-clipboard/clipboard: 1.13.2 => 1.13.2 
    @react-native-community/blur: 4.4.0 => 4.4.0 
    @react-native-community/datetimepicker: 8.1.1 => 8.1.1 
    @react-native-community/geolocation: 3.2.1 => 3.2.1 
    @react-native-community/netinfo: 11.3.2 => 11.3.2 
    @react-native-community/slider: 4.4.3 => 4.4.3 
    @react-native-firebase/analytics: 19.2.0 => 19.2.0 
    @react-native-firebase/app: 19.2.0 => 19.2.0 
    @react-native-firebase/messaging: 19.2.0 => 19.2.0 
    @react-native-masked-view/masked-view: 0.2.9 => 0.2.9 
    @react-native-picker/picker: 2.5.1 => 2.5.1 
    @react-native-segmented-control/segmented-control: 2.5.0 => 2.5.0 
    @react-native/babel-preset: 0.74.85 => 0.74.85 (0.73.21)
    @react-native/eslint-config: 0.74.85 => 0.74.85 
    @react-native/metro-config: 0.74.85 => 0.74.85 
    @react-native/typescript-config: 0.74.85 => 0.74.85 
    @react-navigation/bottom-tabs: 6.6.0 => 6.6.0 
    @react-navigation/elements: 1.3.30 => 1.3.30 
    @react-navigation/native: 6.1.17 => 6.1.17 
    @react-navigation/native-stack: 6.10.0 => 6.10.0 
    @sayem314/react-native-keep-awake: 1.2.2 => 1.2.2 
    @sentry/react-native: 5.24.1 => 5.24.1 
    @shopify/flash-list: 1.6.4 => 1.6.4 
    @shopify/react-native-skia: 1.2.3 => 1.2.3 
    @statsig/js-client: ^1.4.0 => 1.4.0 
    @statsig/react-native-bindings: ^1.4.0 => 1.4.0 
    @testing-library/react-hooks: 8.0.1 => 8.0.1 
    @trivago/prettier-plugin-sort-imports: 4.3.0 => 4.3.0 
    @turf/distance: 7.0.0 => 7.0.0 
    @turf/helpers: 7.0.0 => 7.0.0 
    @turf/length: 7.0.0 => 7.0.0 
    @turf/line-slice-along: 7.0.0 => 7.0.0 
    @types/chroma-js: 2.4.4 => 2.4.4 
    @types/emoji-flags: 1.3.3 => 1.3.3 
    @types/eslint: 8.56.5 => 8.56.5 
    @types/jest: 29.2.1 => 29.2.1 
    @types/jwt-decode: 3.1.0 => 3.1.0 
    @types/lodash.isequal: 4.5.8 => 4.5.8 
    @types/lodash.merge: 4.6.9 => 4.6.9 
    @types/lodash.throttle: 4.1.9 => 4.1.9 
    @types/pako: 2.0.0 => 2.0.0 
    @types/react: 18.2.56 => 18.2.56 
    @types/react-native-keep-awake: 2.0.8 => 2.0.8 
    @types/react-native-snap-carousel: 3.8.11 => 3.8.11 
    @types/react-select-country-list: 2.2.3 => 2.2.3 
    @types/react-test-renderer: 18.0.0 => 18.0.0 
    @types/seedrandom: 3.0.8 => 3.0.8 
    @types/voca: 1.4.5 => 1.4.5 
    @typescript-eslint/eslint-plugin: 6.21.0 => 6.21.0 (7.15.0)
    @typescript-eslint/parser: 6.13.0 => 6.13.0 (7.15.0)
    ContextAPIMixpanel:  0.0.1 
    HelloWorld:  0.0.1 
    MixpanelDemo:  0.0.1 
    SimpleMixpanel:  0.0.1 
    acorn: 8.11.3 => 8.11.3 (8.10.0)
    apollo-link-sentry: 4.0.0 => 4.0.0 
    apollo-link-serialize: 4.0.0 => 4.0.0 
    apollo3-cache-persist: 0.15.0 => 0.15.0 
    appcenter-cli: 3.0.0 => 3.0.0 
    autolinker: 3.16.2 => 3.16.2 
    aws-amplify: 6.5.0 => 6.4.3 
    aws-amplify/adapter-core:  undefined ()
    aws-amplify/analytics:  undefined ()
    aws-amplify/analytics/kinesis:  undefined ()
    aws-amplify/analytics/kinesis-firehose:  undefined ()
    aws-amplify/analytics/personalize:  undefined ()
    aws-amplify/analytics/pinpoint:  undefined ()
    aws-amplify/api:  undefined ()
    aws-amplify/api/server:  undefined ()
    aws-amplify/auth:  undefined ()
    aws-amplify/auth/cognito:  undefined ()
    aws-amplify/auth/cognito/server:  undefined ()
    aws-amplify/auth/enable-oauth-listener:  undefined ()
    aws-amplify/auth/server:  undefined ()
    aws-amplify/data:  undefined ()
    aws-amplify/data/server:  undefined ()
    aws-amplify/datastore:  undefined ()
    aws-amplify/in-app-messaging:  undefined ()
    aws-amplify/in-app-messaging/pinpoint:  undefined ()
    aws-amplify/push-notifications:  undefined ()
    aws-amplify/push-notifications/pinpoint:  undefined ()
    aws-amplify/storage:  undefined ()
    aws-amplify/storage/s3:  undefined ()
    aws-amplify/storage/s3/server:  undefined ()
    aws-amplify/storage/server:  undefined ()
    aws-amplify/utils:  undefined ()
    babel-jest: 29.6.3 => 29.6.3 (29.7.0)
    babel-loader: 9.1.3 => 9.1.3 
    babel-plugin-module-resolver: 5.0.0 => 5.0.0 
    chroma-js: 2.4.2 => 2.4.2 
    compare-versions: 4.1.4 => 4.1.4 
    country-codes-list: 1.6.11 => 1.6.11 
    cspell: 6.31.2 => 6.31.2 
    currency-symbol-map: 5.1.0 => 5.1.0 
    date-fns: 3.6.0 => 3.6.0 (2.29.3)
    emoji-flags: 1.3.0 => 1.3.0 
    eslint: 8.57.0 => 8.57.0 
    eslint-plugin-ft-flow: 3.0.11 => 3.0.11 (2.0.3)
    eslint-plugin-jest: 28.6.0 => 28.6.0 (27.9.0)
    eslint-plugin-jsx-expressions: 1.3.2 => 1.3.2 
    eslint-plugin-prettier: 5.2.1 => 5.2.1 (4.2.1)
    eslint-plugin-react-hooks: 4.6.2 => 4.6.2 
    flexsearch: 0.7.43 => 0.7.43 
    formik: 2.4.5 => 2.4.5 
    glob: 10.3.15 => 10.3.15 (7.2.3, 7.1.6, 7.2.0, 8.1.0)
    graphql: 16.8.1 => 16.8.1 (15.8.0)
    husky: 9.0.11 => 9.0.11 
    jest: 29.6.3 => 29.6.3 
    jest-extended: ^4.0.2 => 4.0.2 
    js-base64: 3.7.5 => 3.7.5 
    jwt-decode: 3.1.2 => 3.1.2 
    lint-staged: 13.2.3 => 13.2.3 
    lodash.get: 4.4.2 => 4.4.2 
    lodash.isequal: 4.5.0 => 4.5.0 
    lodash.merge: 4.6.2 => 4.6.2 
    lodash.throttle: 4.1.1 => 4.1.1 
    lottie-react-native: 6.7.2 => 6.7.2 
    mixpanel-react-native: 2.4.1 => 2.4.1 
    native-base: 3.4.28 => 3.4.28 
    pako: 2.1.0 => 2.1.0 (1.0.11)
    patch-package: 8.0.0 => 8.0.0 
    pod-install: 0.2.2 => 0.2.2 
    postinstall-postinstall: 2.1.0 => 2.1.0 
    prettier: 3.1.0 => 3.1.0 (3.2.5)
    react: 18.2.0 => 18.2.0 
    react-native: 0.74.3 => 0.74.3 (0.73.6)
    react-native-android-location-enabler: 2.0.1 => 2.0.1 
    react-native-animated-pagination-dots: 0.1.73 => 0.1.73 
    react-native-app-auth: 7.2.0 => 7.2.0 
    react-native-appsflyer: 6.13.1 => 6.13.1 
    react-native-autolink: 4.2.0 => 4.2.0 
    react-native-background-color: 0.0.8 => 0.0.8 
    react-native-background-fetch: 4.2.5 => 4.2.5 
    react-native-background-geolocation: 4.16.0 => 4.16.0 
    react-native-ble-plx: 2.0.3 => 2.0.3 
    react-native-blob-util: 0.19.9 => 0.19.9 
    react-native-bootsplash: 5.5.3 => 5.5.3 
    react-native-calendars: 1.1305 => 1.1305.0 
    react-native-change-icon: 4.0.0 => 4.0.0 
    react-native-clean-project: 4.0.3 => 4.0.3 
    react-native-code-push: 8.2.1 => 8.2.1 
    react-native-confetti-cannon: 1.5.2 => 1.5.2 
    react-native-config: 1.5.1 => 1.5.1 
    react-native-device-info: 11.1.0 => 11.1.0 
    react-native-email-link: 1.16.1 => 1.16.1 
    react-native-fast-image: 8.6.3 => 8.6.3 
    react-native-fbsdk-next: 13.0.0 => 13.0.0 
    react-native-gesture-handler: 2.16.2 => 2.16.2 
    react-native-get-random-values: 1.11.0 => 1.11.0 
    react-native-haptic-feedback: 2.2.0 => 2.2.0 
    react-native-image-crop-picker: 0.40.3 => 0.40.3 
    react-native-in-app-review: 4.3.3 => 4.3.3 
    react-native-inappbrowser-reborn: 3.7.0 => 3.7.0 
    react-native-launch-arguments: 4.0.2 => 4.0.2 
    react-native-linear-gradient: 2.8.3 => 2.8.3 
    react-native-localization: 2.3.2 => 2.3.2 
    react-native-localize: 3.1.0 => 3.1.0 
    react-native-logs: 5.0.1 => 5.0.1 
    react-native-maps: 1.8.1 => 1.8.1 
    react-native-markdown-display: 7.0.2 => 7.0.2 
    react-native-mmkv: 2.12.2 => 2.12.2 
    react-native-modal: 13.0.1 => 13.0.1 
    react-native-offline: 6.0.2 => 6.0.2 
    react-native-pdf: 6.7.5 => 6.7.5 
    react-native-permissions: 4.1.5 => 4.1.5 
    react-native-purchasely: 4.3.3 => 4.3.3 
    react-native-purchases: 7.28.0 => 7.28.0 
    react-native-pure-jwt: 3.0.2 => 3.0.2 
    react-native-qrcode-svg: 6.3.0 => undefined (6.3.0, )
    react-native-rb-appearance: link:./modules/rb-appearance => 1.0.0 
    react-native-reanimated: 3.13.0 => 3.13.0 
    react-native-reanimated-carousel: 3.5.1 => 3.5.1 
    react-native-restart: 0.0.27 => 0.0.27 
    react-native-safe-area-context: 4.10.7 => 4.10.7 (4.10.3)
    react-native-screens: 3.32.0 => 3.32.0 
    react-native-sensors: 7.3.6 => 7.3.6 
    react-native-sha256: 1.4.10 => 1.4.10 
    react-native-share: 10.2.1 => 10.2.1 
    react-native-sound: 0.11.2 => 0.11.2 
    react-native-svg: 15.3.0 => 15.3.0 
    react-native-svg-transformer: 1.3.0 => 1.3.0 
    react-native-text-ticker: 1.14.0 => 1.14.0 
    react-native-toast-message: 2.2.0 => 2.2.0 
    react-native-tts: 4.1.1 => 4.1.1 
    react-native-url-polyfill: 2.0.0 => 2.0.0 
    react-native-video: 6.4.3 => 6.4.3 
    react-native-view-shot: 3.8.0 => 3.8.0 
    react-native-watch-connectivity: 1.1.0 => 1.1.0 
    react-native-webview: 13.8.1 => 13.8.1 (11.26.1)
    react-native-youtube-iframe: 2.3.0 => 2.3.0 
    react-select-country-list: 2.2.3 => 2.2.3 
    react-test-renderer: 18.1.0 => 18.1.0 
    reactotron-react-native: 5.1.7 => 5.1.7 
    rn-android-keyboard-adjust: 2.1.2 => 2.1.2 
    scheduler: 0.23.2 => 0.23.2 (0.24.0-canary-efb381bbf-20230505, 0.21.0, 0.22.0)
    seedrandom: 3.0.5 => 3.0.5 
    semver: 7.6.2 => 7.6.2 (6.3.1, 7.3.5, 5.7.2)
    sharp: 0.32.6 => 0.32.6 
    simplify-js: 1.2.4 => 1.2.4 
    standard-version: 9.5.0 => 9.5.0 
    styled-components: 6.1.11 => 6.1.11 
    styled-components/native:  undefined ()
    styled-system: 5.1.5 => 5.1.5 
    svgo: 3.2.0 => 3.2.0 
    timezone-mock: 1.3.6 => 1.3.6 
    typescript: 5.0.4 => 5.0.4 
    use-context-selector: 1.4.1 => 1.4.1 
    use-debounce: 10.0.0 => 10.0.0 
    use-memo-one: 1.1.3 => 1.1.3 
    uuid: 10.0.0 => 8.3.2 (9.0.1, 7.0.3)
    victory-native: 41.0.1 => 41.0.1 
    voca: 1.4.1 => 1.4.1 
    yup: 1.4.0 => 1.4.0 
    yup-password: 0.4.0 => 0.4.0 
  npmGlobalPackages:
    conventional-changelog-cli: 5.0.0
    corepack: 0.22.0
    npm: 10.2.4
    standard-changelog: 6.0.0


Describe the bug

In our app we call fetchAuthSession() when the app load so that we can get the latest idToken toke to use with our API requests. However randomly for some users they get the error {"name":"Unknown","underlyingError":{}} which then results in the idToken token getting removed from async storage.

Expected behavior

The user is logged in, and a valid idToken should be returned

Reproduction steps

  1. log user in
  2. when app mounts call await fetchAuthSession() to get latest token or refresh the token
  3. await fetchAuthSession() will throw an error randomly for some users (FYI we have over 200,000 MAU's)

Code Snippet

const setIdTokenFromSession = useCallback(async (forceRefresh?: boolean) => {
		log.debug('Setting id token from session', { forceRefresh })
		try {
			const session = await fetchAuthSession()
			const idToken = session.tokens?.idToken?.toString()
			if (idToken) {
				log.debug('Setting id token in ref')
				idTokenRef.current = idToken
				return idToken
			}
		} catch (e) {
			log.error('Error setting id token from session', e)
		}
	}, [])

Log output

// Put your logs below this line


aws-exports.js

No response

Manual configuration

export const amplifyConfig: ResourcesConfig = {
	Auth: {
		Cognito: {
			// OPTIONAL - Amazon Cognito User Pool ID
			userPoolId: Config.COGNITO_USER_POOL_ID as string,

			// OPTIONAL - Amazon Cognito Web Client ID (26-char alphanumeric string)
			userPoolClientId: Config.COGNITO_WEB_CLIENT_ID as string,

			// REQUIRED only for Federated Authentication - Amazon Cognito Identity Pool ID
			// identityPoolId: 'XX-XXXX-X:XXXXXXXX-XXXX-1234-abcd-1234567890ab',

			// OPTIONAL - Enforce user authentication prior to accessing AWS resources or not
			// mandatorySignIn: false,

			loginWith: {
				// OPTIONAL - Hosted UI configuration
				oauth: {
					domain: `${Config.ENVIRONMENT}.auth.runna.com`,
					scopes: ['email', 'openid', 'profile', 'aws.cognito.signin.user.admin'],
					redirectSignIn: [`${Config.APP_ID}://app`],
					redirectSignOut: [`${Config.APP_ID}://welcome`],
					responseType: 'code', // or 'token', note that REFRESH token will only be generated when the responseType is code
				},
			},
		},
	},
}

Additional configuration

No response

Mobile Device

No response

Mobile Operating System

No response

Mobile Browser

No response

Mobile Browser Version

No response

Additional information and screenshots

No response

walterholohan avatar Aug 14 '24 21:08 walterholohan

Hey @cwomack , thanks for picking up. Happy to jump a call to help triage further if that helps.

Also if you have any other workarounds that would be super helpful i.e. do we just directly hit the cognito endpoints in order to refresh the token?

if you want to check out our app its https://runna.com

walterholohan avatar Aug 15 '24 06:08 walterholohan

Hello, @walterholohan and sorry to hear you've got users running into this. It may be hard to identify why this is happening with the information provided due to these types of unknown errors get asserted in every Auth API (see here). It's odd that the underlyingError object is empty though.

Can you provide the stack trace of the error if you have it? Or possibly get more details from the network request when this happens? Are you able to access the AuthError.underlyingError and print that out?

cwomack avatar Aug 15 '24 19:08 cwomack

Thanks for the reply Chris. I will add in more debugging logs to see if I can expose more of the error.

In the meantime, should I go pure vanilla in order to refresh the access tokens?

i.e.

  • get the refreshToken from async storage
  • make a HTTP POST request to the cognito refresh endpoint
  • then get the new access token and persist to storage

walterholohan avatar Aug 16 '24 14:08 walterholohan

@walterholohan, we're hesitant to make any recommendations to manually start making HTTP Post requests to the Cognito endpoints without seeing the debugging logs/errors. Do you know if any of the users that experience this also have network issues or slow connections?

cwomack avatar Aug 16 '24 19:08 cwomack

Yep I can see in Sentry a few slow network/no network requests.

In our app, if no network connection then we still want the user to be logged in and we show them cached content which we persist to local storage.

To determine if they are logged in we check async storage to see if a refresh token is present.

Do you think fetchAuthSession is clearing async storage if no network or if the refresh request fails? I can see from logs in sentry it usually when a user opens app more than 24 hours since last session (i.e. access token is 24 hours) so fetchAuthSession I presume would try refresh the token under the hood

walterholohan avatar Aug 16 '24 19:08 walterholohan

@walterholohan, fetchAuthSession() should attempt to refresh after the access token has expired (providing there's a valid refresh token as well). As for network errors and how that changes the behavior, fetchAuthSession() will clear tokens if an error is NOT a network error. However, if your users are getting network errors then that shouldn't result in tokens getting cleared (assuming valid refresh token).

Just to summarize my understanding of what's happening so far so we can attempt to reproduce on our side better:

  1. Sign in with a user and wait for access token to expire (24 hour TTL for access token)
  2. Go offline
  3. With expired access token, valid refresh token, and app offline, call fetchAuthSession() API
  4. Observe the behavior of async storage within the React Native app to confirm if tokens are cleared (presumably after network error is thrown)

That look proper for reproduction? And are you able to reproduce this yourself locally at all? If so, can you verify by inspecting your async storage that the tokens are not there?

cwomack avatar Aug 19 '24 20:08 cwomack

Hey @cwomack sorry about the delay. I added some extra logs to our app and was just waiting to see what came back. Below is what I found

Sentry shows that there is some timeout or network issue when calling the cognito endpoint image

After this fetchAuthSession() will return the below error

{"name":"Unknown","message":"An unknown error has occurred.","underlyingError":{}}

After this on some occasion's the tokens will be removed from async storage.

I have tried to replicate locally but was unable too, but it seems some users get the Unknown error

walterholohan avatar Aug 29 '24 15:08 walterholohan

@cwomack we seem to be getting a lot of people now where the token is failing to refresh, even though our refresh token expiry is set to 3 years and we have only been using Cognito for 1 year.

Just for context, we fire off quite a few API requests when the app launches, and on each request we check if the token has expired or not. Do you think if we fired fetchAuthSession multiple times in a short space of time then would this affect anything?

As mentioned above is there any other primitive way of refreshing the token? fetchAuthSession is quite abstracted so its hard to see from the source code what is happening.

Or happy to jump on a 30 minute call either and I can show you what we do in the app?

walterholohan avatar Aug 31 '24 12:08 walterholohan

@walterholohan, it sounds like there's a possibility this is related to the Quota Limits in Cognito. While the InitiateAuth call has been deduped to ensure there's less calls happening with Cognito each time, both GetId and GetCredentialsForIdentity are not, and are likely hitting the limits (seen here).

Can you help us verify this by clarifying how many calls are made to fetchAuthSession() per each device as well as provide any screenshots or additional data of the server logs when failures happen?

cwomack avatar Sep 04 '24 18:09 cwomack

So at one stage we were making the fetchAuthSession() before every API call thinking that it would just return the idToken from async store if it was not expired and then if it was expired it would refresh the token. However at the weekend I refactored it so we just make a call once on app start, and then save the idToken in memory and only call fetchAuthSession if the token has expired.

const getIdToken = useCallback(async () => {
		try {
			if (!idTokenRef.current) {
				const idTokenKey = (await AsyncStorage.getAllKeys()).find(key => key.includes('idToken'))
				const idToken = await AsyncStorage.getItem(idTokenKey || '')

				if (idToken) {
					log.debug('Setting id token ref from async storage')
					idTokenRef.current = idToken
				} else {
					log.debug('No id token found in async storage')
				}
			}

			if (idTokenRef.current) {
				// Check if the token is expired
				const idTokenJWT = decodeJWT(idTokenRef.current)
				if (idTokenJWT?.exp && idTokenJWT.exp * 1000 < Date.now()) {
					log.debug('Id token is expired, refreshing')
					try {
						const session = await fetchAuthSession()
						const idToken = session.tokens?.idToken?.toString()
						if (idToken) {
							log.debug('Setting id token in ref')
							idTokenRef.current = idToken
						} else {
							log.debug('No id token found in session')
						}
					} catch (e) {
						if (e instanceof AuthError) {
							log.debug(
								JSON.stringify({
									name: e.name,
									message: e.message,
									error: e.underlyingError,
									recovery: e.recoverySuggestion,
								}),
							)
							if (e.name !== 'Unknown') {
								log.error('Error fetchAuthSession')
							}
						} else {
							log.error('Error refreshing idToken', e)
						}
					}
				}
				return idTokenRef.current
			}
			log.debug('No id token found in async storage, return null')
			return null
		} catch (e) {
			log.error('Error getting id token', e)
			return null
		}
	}, [])

FYI we have no server logs as we use AWS AppSync and use cognito as the authentication source

walterholohan avatar Sep 04 '24 19:09 walterholohan

@walterholohan, thanks for the follow up. Wanted to check in and see if the refactoring has helped at all from getting the errors (and possibly confirming that it was the quota limits from Cognito that were the culprit). Let us know if you're still running into this?

cwomack avatar Sep 10 '24 20:09 cwomack

@cwomack unfortunately we are still getting user's whose tokens are getting wiped from async storage. It seems like if we hit fetchAuthSession with a few concurrent requests then the token will return as undefined and the user will not have a uth session anymore.

I checked our Cognito quota in AWS but we were hitting now limits. Does each user have a limit too?

walterholohan avatar Sep 15 '24 20:09 walterholohan

Hey @cwomack sorry about the delay. I added some extra logs to our app and was just waiting to see what came back. Below is what I found

Sentry shows that there is some timeout or network issue when calling the cognito endpoint image

After this fetchAuthSession() will return the below error

{"name":"Unknown","message":"An unknown error has occurred.","underlyingError":{}}

After this on some occasion's the tokens will be removed from async storage.

I have tried to replicate locally but was unable too, but it seems some users get the Unknown error

Hi @walterholohan when you get the logs of the underlying network requests made for fetchAuthSession, were you also able to collect the request headers info?

HuiSF avatar Sep 19 '24 16:09 HuiSF

@HuiSF unfortunately the headers don't appear in the Sentry logs, however I can connect the app to a debugger and get the headers for you. However it prob wont be for a failure as its very hard to replicate

walterholohan avatar Sep 19 '24 20:09 walterholohan

@HuiSF apologies for the delay but below is a screenshot of the request headers.

image

Luckily in some Postman scripts we had similar headers set to refresh token's for tests user's which were taken from the mobile app when we were on version 5 of amplify, and you can see that the x-amz-user-agent was slightly different. Do you think this would make a difference?

image

Just for context for a steady stream of around 20+ users a day who experience this issue). Is their anything else I can do in order to help debug? I reached out to AWS Business support and they had a look at the cloudwatch logs and couldn't find any rate limiting on the requests

@cwomack any luck on your side?

walterholohan avatar Oct 08 '24 19:10 walterholohan

Thanks @walterholohan but I'm more looking to see the headers for a failed request, the screenshot you provided showed a successful request (200) :D

HuiSF avatar Oct 09 '24 18:10 HuiSF

@HuiSF I am unable to reproduce locally. However is there a way I can view the API logs in AWS console? ChatGPT says I can do below

image

walterholohan avatar Oct 09 '24 18:10 walterholohan

View service APIs events can be done in AWS Console, for example you can enable CloudTrail events for the Cognito User Pool and Identity Pool and to monitor the service APIs calls status. Note that logging data events incurs additional charges.

HuiSF avatar Oct 09 '24 19:10 HuiSF

Thanks I will give that a go now.

Also I just enabled the below integration in Sentry which should hopefully log more data about the failed requests so I can get more info for you

image

walterholohan avatar Oct 09 '24 19:10 walterholohan

I was just going through the Cloudtrial event for InitiateAuth and cant find any logs for a user who I know was experiencing the issue. Which makes me believe something is happening within the SDK where its not making the request to refresh the token.

For example we might have 3-4 API calls trigger at the same time, and if the token is expired there might be a scenario where they all call fetchAuthSession() at the same time. Will this cause any issue's within the SDK? i.e. will it hit ay race conditions which might cause it to clear the auth session?

walterholohan avatar Oct 09 '24 19:10 walterholohan

For example we might have 3-4 API calls trigger at the same time, and if the token is expired there might be a scenario where they all call fetchAuthSession() at the same time.

By "they" you mean the same end user account? (identified by looking at the sourceIPAddress field of the event)

Also since we are looking at the failed fetchAuthSession() after a user has signed in, the corresponding InitiateAuth event would have requestParameters.authFlow as REFRESH_TOKEN_AUTH if you don't see any failures on this call, it may be that the identity pool GetId server call is the bottleneck (by default service limits requests for this call as 25 per second (reference))

HuiSF avatar Oct 11 '24 16:10 HuiSF

Yep the same user i.e. there could be a scenario where the app opens, the token is expired and we fire off 3-4 network requests at the same time. In our logic, if we get a 401 from the server, then we try to refresh the token so theoretically we might get a burst of 401's and then we hit fetchAuthSession().

Update from some extra logs I added last week which was then release in a new app version. Below is a snippet of the code we use to refresh and also log errors. We are getting lots of people who are hitting the log message Id token is still expired which means fetchAuthSession() is called but returning back the old expired token. I checked Sentry for network requests but in each of these cases the app did not make a network request to cognito in order to refresh the token.

@cwomack AWS business support has been reaching out to you, do you think its best we jump on a call for 30 mins to see if we can solve this?

const getIdToken = useCallback(async () => {
		try {
			if (!idTokenRef.current) {
				const idTokenKey = (await AsyncStorage.getAllKeys()).find(key => key.includes('idToken'))
				const idToken = await AsyncStorage.getItem(idTokenKey || '')

				if (idToken) {
					log.debug('Setting id token ref from async storage')
					idTokenRef.current = idToken
				} else {
					log.debug('No id token found in async storage')
				}
			}

			if (idTokenRef.current) {
				// Check if the token is expired
				const idTokenJWT = decodeJWT(idTokenRef.current)
				if (idTokenJWT?.exp && idTokenJWT.exp * 1000 < Date.now()) {
					log.debug('Id token is expired, refreshing')
					try {
						const session = await fetchAuthSession()
						const idToken = session.tokens?.idToken?.toString()
						if (idToken) {
							log.debug('Setting id token in ref', JSON.stringify(session.tokens?.idToken?.payload))

							// adding a error here so we can debug more in Sentry
							if (session.tokens?.idToken?.payload.exp && session.tokens?.idToken?.payload.exp * 1000 < Date.now()) {
								log.error('Id token is still expired')
							}
							idTokenRef.current = idToken
						} else {
							log.debug('No id token found in session')
						}
					} catch (e) {
						if (e instanceof AuthError) {
							log.debug(
								JSON.stringify({
									name: e.name,
									message: e.message,
									error: e.underlyingError,
									recovery: e.recoverySuggestion,
								}),
							)
							if (e.name !== 'Unknown') {
								log.error('Error fetchAuthSession')
							} else {
								log.error('Error Unknown Cognito AuthError')
							}
						} else {
							log.error('Error refreshing idToken', e)
						}
					}
				}
				return idTokenRef.current
			}
			log.debug('No id token found in async storage, return null')
			return null
		} catch (e) {
			log.error('Error getting id token', e)
			return null
		}
	}, [])
	```

walterholohan avatar Oct 14 '24 08:10 walterholohan

@walterholohan, happy to jump on a call if need be. If you'd like, we can coordinate through Discord if you don't mind sending me a DM.

As a side note, we recommend that you always use fetchAuthSession() to get the idToken instead of trying to read it yourself from asyncStorage. The fetchAuthSession() API doesn't always fire a network request when the accessToken is expired.

Also, want to circle back to @HuiSF's comment above asking about the failed request headers. We want to rule out the potential for a bottleneck tied to the invocations of GetId (see here) which have a default limit of 25 per second. This can be increased via a request through AWS Support to raise that quota limit, but seeing the failed headers would help us look more into this.

cwomack avatar Oct 16 '24 21:10 cwomack

@cwomack thanks I just sent you a message on Discord

walterholohan avatar Oct 18 '24 08:10 walterholohan

@walterholohan, thanks! Will follow up there (and disregard the linked PR, was a clipboard + copy error).

cwomack avatar Oct 18 '24 23:10 cwomack

Thanks @cwomack, FYI I sent you a friend request on Discord

walterholohan avatar Oct 21 '24 08:10 walterholohan

We are also seeing a case where users are randomly signed out, with local storage being cleared. We had a moment where this reoccured a lot and fixed it partially by passing { forceRefresh: true } into our initialization function for our authentication context, not sure if this was just random though.

This was part of a larger update, which makes it harder to narrow down, but a part of that update was upgrading Amplify from version 4 to version 6, which feels like the likely culprit. Another thing that might be related is that we now have seperate lambda authorizers in the backend, which means more calls to Cognito, but I can't see that being the entire reason.

maxscn avatar Oct 25 '24 13:10 maxscn

@MaximilianSchon the upgrade to v6 was also main culprit for us

walterholohan avatar Oct 25 '24 16:10 walterholohan

We also are experiencing issues with fetchAuthSession in v6 used on a similar context.

Calling a code similar to this before every request seems to perform odd when a users was inactive for a long period of time.

    let session = await fetchAuthSession();

    let idToken = session?.tokens?.idToken;
    return idToken?.toString();

With a cookie storage similar

cognitoUserPoolsTokenProvider.setKeyValueStorage(
    new CookieStorage({
      domain: '.example.com',
      path: '/',
      expires: 7,
      secure: true,
    })
  );

The way we have constantly been able to reproduce this was to set the id token and access token lifetime to 5 minutes. After login you don't interact with the website at all, after 5-6 minutes in another tab open the developer console to see all the logs and api calls and enter the website's URL in the browser. We see the api calls to the AWS Cognito URL's but the objects returned by fetchAuthSession is an object filled with undefined for all the values.

Comparing this to another project that runs on: "@aws-amplify/auth": "^4.1.0", "@aws-amplify/core": "^4.1.2" And has almost the same code for the context provider, we don't see the degradation on v4.

Current workaround is to refresh the page on the first undefined returned by fetchAuthSession.

stmihai1337 avatar Oct 30 '24 20:10 stmihai1337

@stmihai1337, appreciate the additional context and follow up here. To your point about the ID and Access tokens being set to have a TTL of 5 min, then awaiting 5-6 min to call fetchAuthSession(), it sounds like this would be expected behavior per the "minimum remaining validity" needed from Cognito (see here).

While this might reproduce similar (if not the same) issue that @walterholohan is experiencing, we're still looking into this to see if there's either improvements to be made on how fetchAuthSession() is handling these situations or if this is a bug in our code base.

I'm following up with @walterholohan outside of Github to review this, but we'll comment back on this issue once we've met and have more details.

cwomack avatar Oct 31 '24 18:10 cwomack