Amplify-android: Amplify.Auth.currentUser sporadically returns null after successful sign in

[queden]

As mentioned in #826 comments, I am signing a user into Amplify and receiving that the sign in was successful.

I then try to fetch the currentUser using Amplify.Auth.currentUser. Approximately a quarter of the time, this fails, even after a successful sign in. On failure, it throws the following error:

2020-09-21 18:07:57.160 8168-8168/io.appatech.appa E/AndroidRuntime: FATAL EXCEPTION: main
    Process: [PROJECT_PATH], PID: 8168
    java.lang.RuntimeException: Unable to start activity ComponentInfo{[PROJECT_PATH]/[PROJECT_PATH].activities.MainActivity}: java.lang.IllegalStateException: Amplify.Auth.currentUser must not be null
        at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:3270)
        at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:3409)
        at android.app.servertransaction.LaunchActivityItem.execute(LaunchActivityItem.java:83)
        at android.app.servertransaction.TransactionExecutor.executeCallbacks(TransactionExecutor.java:135)
        at android.app.servertransaction.TransactionExecutor.execute(TransactionExecutor.java:95)
        at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2016)
        at android.os.Handler.dispatchMessage(Handler.java:107)
        at android.os.Looper.loop(Looper.java:214)
        at android.app.ActivityThread.main(ActivityThread.java:7356)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:930)
     Caused by: java.lang.IllegalStateException: Amplify.Auth.currentUser must not be null
        at io.appatech.appa.activities.MainActivity.onCreate(MainActivity.kt:52)
        at android.app.Activity.performCreate(Activity.java:7802)
        at android.app.Activity.performCreate(Activity.java:7791)
        at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1299)
        at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:3245)

Once it fails, the app crashes for a few seconds and then resumes with the user logged in.

The rest of the time, the retrieval succeeds.

Previously (and what I reported on #826), Auth was failing at retrieving about half the time, and on failure the app permanently crashed, whereas now it resumes after a second being down. I realized in my Gradle file that I was using
com.amplifyframework:core:1.3.0 and com.amplifyframework:aws-auth-cognito:1.3.1. Updating the core package to 1.3.1 is what gives the slightly better but still flawed outcome.

Configuration

I was initially using

com.amplifyframework:core:1.3.0
com.amplifyframework:aws-auth-cognito:1.3.1

but now have both updated to 1.3.1.

I set up the user pool to take a username and password using the Amplify CLI. I am not using Lambdas, but have an identity pool set up.

amplifycongfiguration.json

{
    "api": {
        "plugins": {
            "awsAPIPlugin": {
                "amplifyDatasource": {
                    "endpointType": "GraphQL",
                    "endpoint": "{redacted}",
                    "region": "us-east-2",
                    "authorizationType": "API_KEY",
                    "apiKey": "{redacted}"
                },
                "[project name]": {
                    "endpointType": "GraphQL",
                    "endpoint": "{redacted}",
                    "region": "us-east-2",
                    "authorizationType": "API_KEY",
                    "apiKey": "{redacted}"
                },
                "[api-name]": {
                    "endpointType": "GraphQL",
                    "endpoint": "{redacted}",
                    "region": "us-east-2",
                    "authorizationType": "API_KEY",
                    "apiKey": "{redacted}"
                }
            }
        }
    },
    "auth": {
        "plugins": {
            "awsCognitoAuthPlugin": {
                "UserAgent": "aws-amplify-cli/0.1.0",
                "Version": "0.1.0",
                "IdentityManager": {
                    "Default": {}
                },
                "AppSync": {
                    "Default": {
                        "ApiUrl": "{redacted}",
                        "Region": "us-east-2",
                        "AuthMode": "API_KEY",
                        "ApiKey": "{redacted}",
                        "ClientDatabasePrefix": "{redacted}"
                    }
                },
                "CredentialsProvider": {
                    "CognitoIdentity": {
                        "Default": {
                            "PoolId": "{redacted}",
                            "Region": "us-east-2"
                        }
                    }
                },
                "CognitoUserPool": {
                    "Default": {
                        "PoolId": "{redacted}",
                        "AppClientId": "{redacted}",
                        "AppClientSecret": "{redacted}",
                        "Region": "us-east-2"
                    }
                },
                "Auth": {
                    "Default": {
                        "authenticationFlowType": "USER_SRP_AUTH"
                    }
                }
            }
        }
    }
}

Surrounding code

Sign in is handled in the following function in LoginActivity

fun authSignIn(username: String, password: String) {
        Amplify.Auth.signIn(
            username,
            password,
            { result ->
                Log.d(
                    TAG,
                    if (result.isSignInComplete) "Sign in succeeded" else "Sign in not complete"
                )
                updateUiWithUser()
            },
            { error ->
                Log.e(TAG, error.toString())
                showLoginFailed(error.toString())
            }
        )
    }

On success, the user is redirected from LoginActivity to MainActivity in the updateUiWithUser() function. Otherwise, the user is notified of login failing.

Here is the Main Activity onCreate:

override fun onCreate(savedInstanceState: Bundle?) {
        super.onCreate(savedInstanceState)
        setContentView(R.layout.activity_main)

        //Set up AWS AppSync Client
        mAWSAppSyncClient = AWSAppSyncClient.builder()
            .context(applicationContext)
            .awsConfiguration(AWSConfiguration(applicationContext))
            .build()

        // fetching amplify auth session
        Amplify.Auth.fetchAuthSession(
            { result -> Log.i(TAG, result.toString())},
            { error -> Log.e(TAG, error.toString()) }
        )

        // this is where error is thrown sporadically
        Toast.makeText(this, "${Amplify.Auth.currentUser.userId} is logged in", Toast.LENGTH_LONG).show()

      ...

}

Let me know if there is any other information needed, thanks!

[rjuliano]

You may be getting into a race condition. Out of curiosity, try to move the Toast.makeText... line into the success callback of fetchAuthSession

Amplify.Auth.fetchAuthSession(
            { result -> 
                    Log.i(TAG, result.toString())
                    Toast.makeText(this, "${Amplify.Auth.currentUser.userId} is logged in", Toast.LENGTH_LONG).show()
            },
            { error -> Log.e(TAG, error.toString()) }
        )

[queden]

Ah I see, that would make sense!

I updated my code to:

Amplify.Auth.fetchAuthSession(
            { result ->
                Log.i(TAG, result.toString())
                runOnUiThread {
                    Toast.makeText(this, "${Amplify.Auth.currentUser.userId} is logged in", Toast.LENGTH_LONG).show()
                }
            },
            { error -> Log.e(TAG, error.toString()) }
        )

I then tried logging in about 15-20 times. It worked most times, but I had a failure on one of the first tests and the very last test. One of my teammates cloned my code and is getting more frequent errors. We also both updated to 1.3.2 packages.

Logcat shows that the fetching finished with isSignedIn=true before the failure

2020-09-22 10:06:44.191 4593-4920/[project_path] I/MainActivity: AWSCognitoAuthSession{isSignedIn=true, awsCredentials=AuthSessionResult{value=com.amazonaws.auth.BasicSessionCredentials@{redacted}, error=null, type=SUCCESS}, userSub='AuthSessionResult{value={redacted}, error=null, type=SUCCESS}', identityId='AuthSessionResult{value={redacated}, error=null, type=SUCCESS}', userPoolTokens='AuthSessionResult{value=AWSCognitoUserPoolTokens{accessToken={redacted}}
2020-09-22 10:06:44.764 4593-4593/[project_path] E/AndroidRuntime: FATAL EXCEPTION: main
    Process: [project_path], PID: 4593
    java.lang.IllegalStateException: Amplify.Auth.currentUser must not be null
        at [project_path].activities.MainActivity$onCreate$1$1.run(MainActivity.kt:50)
        at android.os.Handler.handleCallback(Handler.java:883)
        at android.os.Handler.dispatchMessage(Handler.java:100)
        at android.os.Looper.loop(Looper.java:214)
        at android.app.ActivityThread.main(ActivityThread.java:7356)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:492)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:930)

[rjuliano]

The way the code is setup in one of our dependencies, it certainly leaves room for this type of race condition.

I'll discuss some options during our next standup to see what we can do or a reliable workaround. I tried to use hub events, but even those were susceptible to the same issue.

I'd say in the short term, just do something like Amplify.Auth.currentUser?.userId to guard against the null.

[queden]

Okay great. Will do, and I look forward to a resolution. Thanks for the help!!

[queden]

Hi @rjuliano, just wanted to follow up to see if there was any resolution! All good if not, not critical just yet

[TrekSoft]

Not yet - just added to our backlog so we can track it and obviously depending on more +1s and comments here by others we'll prioritize higher.

[queden]

Sounds good! Appreciate the help

[saltonmassally]

I am experiencing a similar issue, especially with confirmSignUp (which appears to happen all the time), thus +1

[TrekSoft]

Thanks for that Salton - could you clarify the steps to reproduce what you're seeing with confirmSignUp?