PostAuth activity not getting called.

[mattinger]

@iainmcgin Our qa finally got a phone into the right state for this to happen. Here's the short version of the activity stack:

Running activities (most recent first):
  TaskRecord{e189f08 #3014 A=com.xfinity.digitalhome U=0 sz=2}
    Run #5: ActivityRecord{becfc11 u0 com.android.chrome/org.chromium.chrome.browser.customtabs.CustomTabActivity t3014}
    Run #4: ActivityRecord{a86dbf9 u0 com.xfinity.digitalhome/.auth.LoginActivity t3014}
  TaskRecord{eb020c6 #3012 A=com.google.android.gm U=0 sz=1}
    Run #3: ActivityRecord{db2673d u0 com.google.android.gm/.ConversationListActivityGmail t3012}
  TaskRecord{71ca3b4 #3008 A=com.google.android.apps.photos U=0 sz=3}
    Run #2: ActivityRecord{cb4ef2b u0 com.google.android.apps.photos/.localmedia.ui.LocalPhotosActivity t3008}
    Run #1: ActivityRecord{6a19a96 u0 com.google.android.apps.photos/.albums.grid.DeviceFoldersActivity t3008}
    Run #0: ActivityRecord{c47be97 u0 com.google.android.apps.photos/.home.HomeActivity t3008}

mResumedActivity: ActivityRecord{becfc11 u0 com.android.chrome/org.chromium.chrome.browser.customtabs.CustomTabActivity t3014}
mLastPausedActivity: ActivityRecord{ae0efd4 u0 com.xfinity.digitalhome/net.openid.appauth.AuthorizationManagementActivity t3014 f}

However, when the RedirectURIReceiverActivity is called, it's interesting that the activity stack dump (via adb shell dumpsys activity activities) doesn't even report AuthorizationManagementActivity as being alive anywhere. Hence it's calling onCreate instead of Resuming it.

Running activities (most recent first):
  TaskRecord{e189f08 #3014 A=com.xfinity.digitalhome U=0 sz=3}
    Run #6: ActivityRecord{e8b4770 u0 com.xfinity.digitalhome/net.openid.appauth.RedirectUriReceiverActivity t3014}
    Run #5: ActivityRecord{becfc11 u0 com.android.chrome/org.chromium.chrome.browser.customtabs.CustomTabActivity t3014}
    Run #4: ActivityRecord{a86dbf9 u0 com.xfinity.digitalhome/.auth.LoginActivity t3014}
  TaskRecord{eb020c6 #3012 A=com.google.android.gm U=0 sz=1}
    Run #3: ActivityRecord{db2673d u0 com.google.android.gm/.ConversationListActivityGmail t3012}
  TaskRecord{71ca3b4 #3008 A=com.google.android.apps.photos U=0 sz=3}
    Run #2: ActivityRecord{cb4ef2b u0 com.google.android.apps.photos/.localmedia.ui.LocalPhotosActivity t3008}
    Run #1: ActivityRecord{6a19a96 u0 com.google.android.apps.photos/.albums.grid.DeviceFoldersActivity t3008}
    Run #0: ActivityRecord{c47be97 u0 com.google.android.apps.photos/.home.HomeActivity t3008}

mResumedActivity: ActivityRecord{e8b4770 u0 com.xfinity.digitalhome/net.openid.appauth.RedirectUriReceiverActivity t3014}
mLastPausedActivity: ActivityRecord{becfc11 u0 com.android.chrome/org.chromium.chrome.browser.customtabs.CustomTabActivity t3014}

I would have expected the AuthorizationManagementActivity to be in the same task record as my LoginActivity which is launching the authorization attempt. I have the full traces if you want them at 3 points in time:

1. When on the custom tab
2. When at a breakpoint in RedirectUriReceiverActivity before it sends the intent for AuthorizationManagementActivity
3. When in the onCreate after that intent has been delivered.

[iainmcgin]

In case this is some device / OS version specific issue, could you give me the device model number, OS version and Chrome version too please?

[mattinger]

I'm not sure if it's a device specific issue, but here's the details:

Nexus 6P
Android 6.0.1
Patch Level 1/1/2016
Build number MMB29P

Chrome: 56.0.2924.87

I think our QA has seen it on other devices, but this is the one where it's happening now. As i said, it's highly intermittent, but when it happens the only way to fix it is to stop the app and start over.

[mattinger]

just let me know if you want the full trace files.

[iainmcgin]

It's not always useful, but if you could generate a full bug report from the device immediately after reproduction of the issue, that's likely to give me some clues:

adb bugreport > bugreport.txt

This can contain sensitive information (account names, etc) so it would probably be best to send this to me directly ([email protected]) rather than posting it here.

[mattinger]

Sorry, i went to lunch and will have to get qa to try to get it back in that state again. The app unloaded from memory on that device. However, i did notice that in a normal functional state, the task list looks as follows:

Running activities (most recent first):
  TaskRecord{ac3af68 #3029 A=com.xfinity.digitalhome U=0 sz=3}
    Run #2: ActivityRecord{e2847a8 u0 com.android.chrome/org.chromium.chrome.browser.customtabs.CustomTabActivity t3029}
    Run #1: ActivityRecord{1e3d078 u0 com.xfinity.digitalhome/net.openid.appauth.AuthorizationManagementActivity t3029}
    Run #0: ActivityRecord{8ece030 u0 com.xfinity.digitalhome/.auth.LoginActivity t3029}

Which leads me to believe that for some reason the AuthorizationManagementActivity is getting closed for some reason.

[iainmcgin]

The weird thing is, it should be OK if the activity is destroyed, as the back stack is supposed to retain the intent details that were used to launch it originally. We designed AuthorizationManagementActivity to utilize this to retain the context for the request. I'll see if I can force reproduction by using a memory constrained emulator.

[morphine9]

@mattinger where have you initialized the AuthorizationService ? I had a similar problem before where I was initializing it just before calling performTokenRequest() after AuthorizationServiceConfiguration and it didn't work for me. (RedirectURIReceiverActivity didn't get started) Fixed that by initializing AuthorizationService in first lifecycle callback onCreate() and it works. ref. #165 Didn't have chance to investigate, if identified as same problem then I'll make some time to dive deep.

[mattinger]

I'm actually creating it right before i make the request, rather than in onCreate. That decision stems back to an earlier issue where the Authorization failed on initialization if you didn't have a supported browser. That has since been fixed if i'm correct.

That being said, i'm not sure why that would be an issue.

On Fri, Mar 3, 2017 at 5:48 PM, morphine9 [email protected] wrote:

@mattinger https://github.com/mattinger where have you initialized the AuthorizationService ? I had a similar problem before where I was initializing it just before calling performTokenRequest() after AuthorizationServiceConfiguration and it didn't work for me. (RedirectURIReceiverActivity didn't get started) Fixed that by initializing AuthorizationService in first lifecycle callback onCreate() and it works. ref. #165 https://github.com/openid/AppAuth-Android/issues/165 Didn't have chance to investigate, if identified as same problem then I'll make some time to dive deep.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/openid/AppAuth-Android/issues/182#issuecomment-284091946, or mute the thread https://github.com/notifications/unsubscribe-auth/AAQgjkN3kUzbAeuzfOWfbZ_jNCqzwK5gks5riJiqgaJpZM4MSfaU .

[mattinger]

@iainmcgin One thing i've also just thought about is that when this happens. As a result, there's no longer an AuthorizationManagementActivity for it to deliver codes to, and thus new ones are created. I'm not not sure how it's even getting into that state, as the auth code redirect should be closing the custom tab.

[mattinger]

I have not been able to pinpoint why the auth manager activity is going away yet. It's intermittent and I haven't found clear steps yet to make it happen

On Mar 9, 2017 14:56, "morphine9" [email protected] wrote:

@iainmcgin https://github.com/iainmcgin Darn now I have the same problem ... "PostActivity" is not getting called @iainmcgin https://github.com/iainmcgin Is there supposed to be a RedirectUriReceiverActivity in any of activity sysdump or bugreport ?

@mattinger https://github.com/mattinger Did you find a solution as to why this is happening ? (I'm combing through bugreport and activity sysdump but nothing stands out)

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/openid/AppAuth-Android/issues/182#issuecomment-285462901, or mute the thread https://github.com/notifications/unsubscribe-auth/AAQgjry0au14em3eW7FIZ8xVudgvU1dbks5rkFl2gaJpZM4MSfaU .

[iainmcgin]

It does seem odd that it is disappearing entirely. One possibility I've seen from odd behavior in my own testing is that sometimes the custom tab closes before it dispatches an intent for a custom scheme redirect. This briefly makes the activity underneath it run, before it is suspended and the target activity is started.

In the case of AuthorizationManagementActivity, this would mean the activity is restarted without the response, which we interpret as the user closing the custom tab and fire the cancelation intent. If all of that were to happen before RedirectUriReceiverActivity is started, then that would explain why AuthorizationManagementActivity is no longer in the back stack.

I'll need to try and confirm that this is actually the cause of the behavior you are seeing. We can possibly mitigate it by waiting for a short duration after onStart() before treating the reload as cancellation.

[mattinger]

@iainmcgin This would not surprise me at all. A (possibly configurable) short delay would probably do the trick if this is indeed the case.

[mattinger]

@iainmcgin Have you been able to get anywhere with this yet?

[iainmcgin]

Sorry, my attention is horribly split at the moment - we have a bunch of deadlines fast approaching for Google I/O. I'll see what I can do next week.

[mattinger]

Thanks. i'm curious under what conditions you've seen the custom tab close first. I'm wondering if i can try to troubleshoot this as well. I just haven't run into a situation where i can produce this reliably.

[mattinger]

Well, i did at least find a way to get it in the right state. I have to click my "sign in" button twice rapidly so that the callback fires twice and i end up with two custom tabs in my task stack, but there's only one AuthorizationManagementActivity:

Running activities (most recent first):
  TaskRecord{c217641 #4715 A=com.xfinity.digitalhome U=0 StackId=1 sz=4}
    Run #4: ActivityRecord{233b0ba u0 com.android.chrome/org.chromium.chrome.browser.customtabs.CustomTabActivity t4715}
    Run #3: ActivityRecord{163fa5f u0 com.xfinity.digitalhome/net.openid.appauth.AuthorizationManagementActivity t4715}
    Run #2: ActivityRecord{77dbb50 u0 com.android.chrome/org.chromium.chrome.browser.customtabs.CustomTabActivity t4715}
    Run #1: ActivityRecord{8352d15 u0 com.xfinity.digitalhome/.auth.LoginActivity t4715}

Then I cancel the one custom tab, and i end up in that state. I'm going to prevent my app from allowing a second click to the signin button by disabling it when it's clicked, and then enabling it in the onResume (in case they cancel, it will resume and re-enable). It's not been reported that this is what is going on, but i can at least get it in that state, which is something. I doubt however, that our users or qa are taking this route to get into that state.

[mattinger]

@iainmcgin Have you made any progress on this?

[mattinger]

@iainmcgin Have you been able to track this down at all? Just need to update my team one way or the other.

[iainmcgin]

Apologies, no leads so far. I only had enough bandwidth to get the 0.6.0 release out, my attention is now diverted back to other projects. If your QA is still seeing the issue with 0.6.0, which I expect they will as nothing fundamentally has changed on that codepath, let me know. If you have time to investigate yourself, I would recommend adding some logging to AuthorizationManagementActivity and RedirectUriReceiverActivity to capture the lifecycle events and see if they are being prematurely resumed without the redirect data. That would help confirm or eliminate one possible cause of your issue.

[jiripospisil]

I think I'm hitting the same issue. I have no manifestPlaceholders specified in the build.gradle file but have the following in the manifest:

<activity android:name="net.openid.appauth.RedirectUriReceiverActivity" tools:node="replace">
  <intent-filter>
    <action android:name="android.intent.action.VIEW"/>
    <category android:name="android.intent.category.DEFAULT"/>
    <category android:name="android.intent.category.BROWSABLE"/>
    <data android:scheme="https"
      android:host="example.com"
      android:path="/callback"/>
  </intent-filter>
</activity>

Now when I do the following (against a completely whiped out emulator running Nexus 5X API 25):

adb shell am start -W -a android.intent.action.VIEW -c android.intent.category.DEFAULT -d "https://example.com/callback"

I get a breakpoint hit at RedirectUriReceiverActivity:48 as expected (I hope) and the current state looks like this.

I have the following the app:

public class LoginActivity extends AppCompatActivity {
    // ...
    private AuthorizationService service;

    @Override
    protected void onCreate(Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        setContentView(R.layout.activity_login);

        // ...
        service = new AuthorizationService(this);
    }
    // ...
}

Initially I had the initialization of the AuthorizationService right before making of the performAuthorizationRequest call but tried the solution mentioned in #165 (with no success).

private void initiateLogin(AuthorizationServiceConfiguration configuration) {
    AuthorizationRequest request = new AuthorizationRequest.Builder(
            configuration,
            "56698545cd8fb6417b0074c9",
            ResponseTypeValues.CODE,
            Uri.parse("https://example.com/callback"))
            .setScope("openid email")
            .build();

    Intent postAuthIntent = new Intent(this, PostLoginActivity.class);
    Intent authCanceledIntent = new Intent(this, LoginCancelledActivity.class);

    service.performAuthorizationRequest(
            request,
            PendingIntent.getActivity(this, request.hashCode(), postAuthIntent, 0),
            PendingIntent.getActivity(this, request.hashCode(), authCanceledIntent, 0));
}

Putting a breakpoint on the performAuthorizationRequest call and dumping the activities gives the following. Now when I resume the execution, a Chrome window opens and I get to the SSO server, log in and get redirected to https://example.com/callback with a code. I assume that at this point the RedirectUriReceiverActivity should intercept the redirect and eventually open PostLoginActivity. Instead, I land on the https://example.com/callback page. Dumping the activities again gives this.

I have to look at the official sample app more closely but I can already see a few differences. The main one being that I do everything on the main thread (I'm trying to keep it as simple as possible for now) and not via ExecutorService (I'm not sure if that makes a difference though).

Feel free to request any additional information (the issue happens every time), I'm not really all that familiar with Android development and I'm not sure how to debug issues like this.

[mattinger]

@iainmcgin It's been some time, but has there been any movement on nailing this down yet?

[iainmcgin]

Sorry, I've been really busy with the OpenYOLO project. I should have some more time next week, I'll take another shot at reproducing the issue based on my suspicions of what could be happening.

[nickyk2407]

@jiripospisil I am also facing same issue."a Chrome window opens and I get to the SSO server, log in and get redirected to https://example.com/callback with a code. I assume that at this point the RedirectUriReceiverActivity should intercept the redirect and eventually open PostLoginActivity. Instead, I land on the https://example.com/callback page". Did you find any solution for this?

[jiripospisil]

@nickyk2407 No, not really. I eventually gave up and used a custom scheme instead.

[iainmcgin]

@nickyk2407 ensure that you have correctly registered the intent filter for the HTTPS domain, and that user interaction is occurring in the browser instance. If there is no user interaction (e.g. the IDP immediately redirects after the authorization request to your redirect URI without a user click), then Chrome will not attempt to hand the request to a registered app.

App links only work reliably on Android M+ so I suggest either you control their usage based on the OS version, or just use custom schemes.

[mattinger]

@iainmcgin Have you been able to spend any time on this? This has been open for quite a long time, and another team in our org is facing a lot of issues around this.

[mattinger]

@iainmcgin I've been able now to produce this consistently. I installed an android 4.4.4 vm into genymotion. I also moved to the startActivityForResult/onActivityResult model, instead of using the service to start the activity.

However, when i call startActivityForResult, i get an immediate callback to onActivityResult, even before the onCreate of AuthorizationManagementActivity is called.

This seems to be due to the launchMode="singleTask" present in the manifest.

Here's a stack overflow post which points out the issue:

https://stackoverflow.com/questions/8960072/onactivityresult-with-launchmode-singletask

Changing that to launchMode="singleTop" fixes things:

    <activity
        android:name="net.openid.appauth.AuthorizationManagementActivity"
        android:exported="false"
        android:launchMode="singleTop"
        android:theme="@android:style/Theme.Translucent.NoTitleBar"
        tools:node="replace" />

[iainmcgin]

@jstimes tells me that the current approach to implement the startActivityForResult model only works on Android 5.0 (API 21) and above - earlier versions immediately fail with a RESULT_CANCELED response. We're looking at alternative ways to implement this that will work on earlier versions of Android, while still preserving the singleTask behavior, which we rely on to correctly clean up the back stack after authorization completes.

As for the original issue, we were never able to consistently reproduce the issue, which is why it remained pretty low priority. @jstimes is taking a more active role in maintaining AppAuth as I'm spread pretty thin across Google's identity projects, so I'll ask him to see if he can reproduce the issue.

[mattinger]

What I ended up doing was setting the authorization management activity to single top launch mode and the redirecturireceiver activity to single task. That seems to have resolved the issue for now. And it works on KitKat and lollipop and above. It's not ideal but it's good enough for now

[iainmcgin]

If it works well for you with singleTop, that's a good data point for us. Last year we had some issues with using singleTop but I forget the specifics at this point; singleTask seemed to work best across the different usage scenarios we had tested.