Clicking a link in Twitter doesn't always show the website

[jonalmeida]

Steps to reproduce

1. Have r-b as your default browser.
2. Click a link in the Twitter app.
3. Observe r-b opening.

Expected behavior

• The link loading should be the link clicked in Twitter.

Actual behavior

• r-b opens without any page loading.

Device information

• Android device: Android 9 (Pixel 2)
• Reference Browser version: 1.0.1906 (Build Import cleaned up version of components sample browser. #1 🦎 67.0a1-20190130001444)

These STR aren't very accurate though because it seems to happen if r-b is recently opened and in-memory for it to be reproducible. Once in that state, I can see the issue consistently.

Once I swipe away the app and try it again, the link loads without any hitches.

Below is log when a link in Twitter is clicked:

    --------- beginning of system
2019-02-04 20:45:06.772 1165-5415/? I/ActivityManager: START u0 {act=android.intent.action.VIEW dat=https://t.co/... flg=0x10000000 cmp=org.mozilla.reference.browser.debug/org.mozilla.reference.browser.IntentReceiverActivity (has extras)} from uid 10141
2019-02-04 20:45:06.773 757-757/? D/android.hardware.power@1.2-service.wahoo-libperfmgr: LAUNCH ON
2019-02-04 20:45:06.801 749-749/? I//vendor/bin/hw/android.hardware.health@2.0-service.wahoo: SRAM data: 2541000
2019-02-04 20:45:06.809 26501-32025/org.mozilla.reference.browser.debug D/GeckoViewModule: dispatch GeckoView:SetFocused, data={"focused":false}
2019-02-04 20:45:06.840 26501-32025/org.mozilla.reference.browser.debug D/GeckoViewModule: dispatch GeckoView:SetActive, data={"active":true}
2019-02-04 20:45:06.841 26501-32025/org.mozilla.reference.browser.debug D/GeckoViewModule: dispatch GeckoView:SetFocused, data={"focused":true}
2019-02-04 20:45:06.852 757-757/? D/android.hardware.power@1.2-service.wahoo-libperfmgr: LAUNCH OFF
2019-02-04 20:45:06.893 26501-32025/org.mozilla.reference.browser.debug D/GeckoScreenOrientation: unlocking
2019-02-04 20:45:06.894 4357-4437/org.mozilla.reference.browser.debug:tab D/GeckoViewContent[C]: receiveMessage: GeckoView:SetActive
2019-02-04 20:45:06.955 2901-2912/? W/InputChannel-JNI: Input channel object 'recents_animation_input_consumer (client)' was finalized without being disposed!
2019-02-04 20:45:07.016 613-647/? W/SurfaceFlinger: Attempting to set client state on removed layer: SnapshotStartingWindow for taskId=7157#0
2019-02-04 20:45:07.016 613-647/? W/SurfaceFlinger: Attempting to destroy on removed layer: SnapshotStartingWindow for taskId=7157#0
2019-02-04 20:45:07.566 1165-1181/? I/system_server: NativeAlloc concurrent copying GC freed 188446(9MB) AllocSpace objects, 80(6MB) LOS objects, 42% free, 30MB/52MB, paused 87us total 119.677ms
2019-02-04 20:45:09.478 825-913/? D/CHRE: @ 45739.199: Parsed nanoapp message from host: app ID 0x476f6f676c00100b, endpoint 0x0, msgType 0, payload size 10
2019-02-04 20:45:09.479 825-913/? I/CHRE: @ 45739.199: [NanoMinion] received MSG Type 0x70, Version 1, 6 bytes
2019-02-04 20:45:09.479 825-913/? I/CHRE: @ 45739.199: [AR_CHRE] request.flush
2019-02-04 20:45:09.479 825-913/? I/CHRE: @ 45739.199: [AR_CHRE] send to host, reason=3, sampleSize=6, transitionSize=0
2019-02-04 20:45:09.479 825-913/? I/CHRE: @ 45739.199: [NanoMinion] sent MSG Type 0x72, Version 0, 90 bytes, MessageId 114

And after r-b is swiped away, the expected logs:

    --------- beginning of system
2019-02-04 20:45:47.416 1165-1814/? I/ActivityManager: START u0 {act=android.intent.action.VIEW dat=https://t.co/... flg=0x10000000 cmp=org.mozilla.reference.browser.debug/org.mozilla.reference.browser.IntentReceiverActivity (has extras)} from uid 10141
2019-02-04 20:45:47.423 757-757/? D/android.hardware.power@1.2-service.wahoo-libperfmgr: LAUNCH ON
2019-02-04 20:45:47.438 5831-5831/org.mozilla.reference.browser.debug W/ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@e7de847
2019-02-04 20:45:47.453 5831-5878/org.mozilla.reference.browser.debug I/Gecko: 1549331147450  addons.xpi  WARN  List of valid built-in add-ons could not be parsed.: [Exception... "Component returned failure code: 0x80520012 (NS_ERROR_FILE_NOT_FOUND) [nsIXPCComponents_Utils.readUTF8URI]"  nsresult: "0x80520012 (NS_ERROR_FILE_NOT_FOUND)"  location: "JS frame :: resource://gre/modules/addons/XPIProvider.jsm :: startup :: line 2203"  data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2203
    callProvider()@resource://gre/modules/AddonManager.jsm:205
    _startProvider()@resource://gre/modules/AddonManager.jsm:654
    startup()@resource://gre/modules/AddonManager.jsm:807
    startup()@resource://gre/modules/AddonManager.jsm:2794
    observe()@jar:jar:file:///data/app/org.mozilla.reference.browser.debug-I8ILTLIpQ-CNRTC2VteB9A==/base.apk!/assets/omni.ja!/components/addonManager.js:66
2019-02-04 20:45:47.482 5831-5916/org.mozilla.reference.browser.debug D/libEGL: loaded /vendor/lib/egl/libEGL_adreno.so
2019-02-04 20:45:47.494 5831-5878/org.mozilla.reference.browser.debug D/GeckoThread: State changed to PROFILE_READY
2019-02-04 20:45:47.521 5831-5878/org.mozilla.reference.browser.debug D/GeckoViewStartup: observe: profile-after-change
2019-02-04 20:45:47.523 5831-5916/org.mozilla.reference.browser.debug D/libEGL: loaded /vendor/lib/egl/libGLESv1_CM_adreno.so
2019-02-04 20:45:47.525 5831-5878/org.mozilla.reference.browser.debug D/GeckoViewTelemetryController: setup - canRecordPrereleaseData true, canRecordReleaseData true
2019-02-04 20:45:47.537 5831-5831/org.mozilla.reference.browser.debug I/SessionStorage/AutoSave: Save: Session added
2019-02-04 20:45:47.539 5831-5831/org.mozilla.reference.browser.debug I/SessionStorage/AutoSave: Save: Session selected
2019-02-04 20:45:47.539 5831-5831/org.mozilla.reference.browser.debug D/SessionStorage/AutoSave: Skipping save, other job already in flight
2019-02-04 20:45:47.548 5831-5923/org.mozilla.reference.browser.debug D/SessionStorage/AutoSave: Delaying save (1986ms)
2019-02-04 20:45:47.554 5831-5916/org.mozilla.reference.browser.debug D/libEGL: loaded /vendor/lib/egl/libGLESv2_adreno.so
2019-02-04 20:45:47.575 1165-1814/? I/ActivityManager: START u0 {act=android.intent.action.VIEW dat=https://t.co/... flg=0x10000000 cmp=org.mozilla.reference.browser.debug/org.mozilla.reference.browser.BrowserActivity (has extras)} from uid 10214
2019-02-04 20:45:47.577 757-757/? D/android.hardware.power@1.2-service.wahoo-libperfmgr: LAUNCH ON
2019-02-04 20:45:47.664 613-647/? D/SurfaceFlinger: duplicate layer name: changing Surface(name=AppWindowToken{673e2ef token=Token{a3893ce ActivityRecord{85610c9 u0 org.mozilla.reference.browser.debug/org.mozilla.reference.browser.IntentReceiverActivity t7158}}})/@0x485fb71 - animation-leash to Surface(name=AppWindowToken{673e2ef token=Token{a3893ce ActivityRecord{85610c9 u0 org.mozilla.reference.browser.debug/org.mozilla.reference.browser.IntentReceiverActivity t7158}}})/@0x485fb71 - animation-leash#1
2019-02-04 20:45:47.672 5831-5831/org.mozilla.reference.browser.debug D/GeckoNetworkManager: Incoming event enableNotifications for state OffNoListeners -> OffWithListeners
2019-02-04 20:45:47.673 5831-5831/org.mozilla.reference.browser.debug D/GeckoNetworkManager: New network state: UP, CELLULAR, CELL_4G
2019-02-04 20:45:47.674 5831-5831/org.mozilla.reference.browser.debug W/ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@1e7a63c
2019-02-04 20:45:47.717 5831-5878/org.mozilla.reference.browser.debug I/Gecko: Attempting load of libEGL.so
2019-02-04 20:45:47.725 5831-5878/org.mozilla.reference.browser.debug I/Adreno: QUALCOMM build                   : 7bf2852, Ie32bfa6f6f
    Build Date                       : 06/03/18
    OpenGL ES Shader Compiler Version: EV031.24.00.00
    Local Branch                     : googdrp
    Remote Branch                    : 
    Remote Branch                    : 
    Reconstruct Branch               : 
2019-02-04 20:45:47.725 5831-5878/org.mozilla.reference.browser.debug I/Adreno: Build Config                     : S L 4.0.10 AArch32
2019-02-04 20:45:47.731 5831-5878/org.mozilla.reference.browser.debug I/Adreno: PFP: 0x005ff110, ME: 0x005ff066
2019-02-04 20:45:47.737 5831-5831/org.mozilla.reference.browser.debug W/e.browser.debu: Accessing hidden method Landroid/view/View;->computeFitSystemWindows(Landroid/graphics/Rect;Landroid/graphics/Rect;)Z (light greylist, reflection)
2019-02-04 20:45:47.738 5831-5831/org.mozilla.reference.browser.debug W/e.browser.debu: Accessing hidden method Landroid/view/ViewGroup;->makeOptionalFitsSystemWindows()V (light greylist, reflection)
2019-02-04 20:45:47.739 5831-5878/org.mozilla.reference.browser.debug I/ConfigStore: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasWideColorDisplay retrieved: 1
2019-02-04 20:45:47.739 5831-5878/org.mozilla.reference.browser.debug I/ConfigStore: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasHDRDisplay retrieved: 0
2019-02-04 20:45:47.783 5831-5831/org.mozilla.reference.browser.debug D/OpenGLRenderer: Skia GL Pipeline
2019-02-04 20:45:47.991 5831-5831/org.mozilla.reference.browser.debug W/e.browser.debu: Accessing hidden field Landroid/widget/EdgeEffect;->mPaint:Landroid/graphics/Paint; (light greylist, reflection)
2019-02-04 20:45:48.036 5831-5831/org.mozilla.reference.browser.debug D/GeckoScreenOrientation: updating to new orientation PORTRAIT_PRIMARY
2019-02-04 20:45:48.037 5831-5878/org.mozilla.reference.browser.debug D/GeckoViewTelemetryController: observed internal-telemetry-geckoview-load-complete - ready to handle telemetry requests
2019-02-04 20:45:48.052 5831-5936/org.mozilla.reference.browser.debug I/GeckoConsole: OpenGL compositor Initialized Succesfully.
    Version: OpenGL ES 3.2 V@313.0 (GIT@7bf2852, Ie32bfa6f6f) (Date:06/03/18)
    Vendor: Qualcomm
    Renderer: Adreno (TM) 540
    FBO Texture Target: TEXTURE_2D
2019-02-04 20:45:48.072 5831-5939/org.mozilla.reference.browser.debug I/OpenGLRenderer: Initialized EGL, version 1.4
2019-02-04 20:45:48.072 5831-5939/org.mozilla.reference.browser.debug D/OpenGLRenderer: Swap behavior 1
2019-02-04 20:45:48.123 5831-5878/org.mozilla.reference.browser.debug D/GeckoThread: State changed to RUNNING
2019-02-04 20:45:48.123 5831-5878/org.mozilla.reference.browser.debug I/GeckoSession: zerdatime 45775206 - chrome startup finished
2019-02-04 20:45:48.128 5831-5878/org.mozilla.reference.browser.debug W/e.browser.debu: Accessing hidden field Ljava/lang/Boolean;->value:Z (light greylist, JNI)
2019-02-04 20:45:48.128 5831-5878/org.mozilla.reference.browser.debug W/e.browser.debu: Accessing hidden field Ljava/lang/Integer;->value:I (light greylist, JNI)
2019-02-04 20:45:48.128 5831-5878/org.mozilla.reference.browser.debug W/e.browser.debu: Accessing hidden field Ljava/lang/Double;->value:D (light greylist, JNI)
2019-02-04 20:45:48.146 1165-1217/? I/ActivityManager: Displayed org.mozilla.reference.browser.debug/org.mozilla.reference.browser.BrowserActivity: +483ms (total +707ms)

[Amejia481]

Looks like when the issue happens we are getting a indirect intent to BrowserActivity instead of to IntentReceiverActivity.

The weird thing is that IntentReceiverActivity has all the intent filters to be called for this action (android.intent.action.VIEW)

[Amejia481]

A video of the issue

[Amejia481]

@jonalmeida and I spent the day debugging this issue 🙃 but It was fun :)

What we found is the following:

1. The Twitter app supports custom tabs and its trying to open the links as custom tabs e.g they call warmup on RB, but when they create the intent, they are not including the extra flag CustomTabsIntent.EXTRA_SESSION android.support.customtabs.extra.SESSION this extra flag identifies custom tabs, and as a result we are not treating the Twitter intents as custom tabs.

The weird part is that they are only including the extra flag, when the default browser is Chrome or FireFox . We could confirm the issue because we changed locally the applicationId of RB to org.mozilla.firefox and we saw that they send us the flag and RB treated the intent as a custom tab.

2. From what I've saw, the issue is happening because the only place where we are handling intents is IntentReceiverActivity. There we use intentProcessor for creating a session from the intents and routing the intents to a custom tab or a normal browser experience.

When the issue happens the intent from Twitter is never hitting IntentReceiverActivity is going directly to BrowserActivity as result, the link is not loading, because IntentReceiverActivity is the only one that knows how to create a session from an intent. We were expecting that an intent always must go first to IntentReceiverActivity and after that to BrowserActivity as we configured the intent-filter for that in theAndroidManifest.xml file.

I could confirm that because, I added logs statements in both IntentReceiverActivity and BrowserActivity. But when the issue happens the logs on IntentReceiverActivity never get executed just the one from BrowserActivity. In addition to that, I added break points to both classes and when the issue occurs just the one on BrowserActivity are getting called.

I suppose this is happening as a side effect of a non-standard implementation . With custom tabs I could replicate the issue. Even @jonalmeida and I could replicate the issue on Focus.

I believe the ActivityManager is getting confused by a non-standard implementation of custom tabs.

✅ These are logs from ActivityManager when the link gets loaded.
IntentReceiverActivity gets called, it creates the session and forwards the call to BrowserActivity that loads the link.

My logs get printed and the break points in both classes get hit ✅

2019-02-27 21:01:40.121 1187-1531/? I/ActivityManager: START u0 {act=android.intent.action.VIEW dat=https://t.co/... flg=0x10000000 cmp=org.mozilla.reference.browser/.IntentReceiverActivity (has extras)} from uid 10184
2019-02-27 21:01:40.201 1187-1531/? I/ActivityManager: START u0 {act=android.intent.action.VIEW dat=https://t.co/... flg=0x10400000 cmp=org.mozilla.reference.browser/.BrowserActivity (has extras)} from uid 10279
2019-02-27 21:01:40.205 1187-1531/? W/ActivityManager: Duplicate finish request for ActivityRecord{511a54c u0 org.mozilla.reference.browser/.IntentReceiverActivity t14329 f}
2019-02-27 21:01:40.291 1187-1230/? I/ActivityManager: Displayed org.mozilla.reference.browser/.IntentReceiverActivity: +144ms

🔴 When the issue happens I get these logs from ActivityManager,

It says that only class called was IntentReceiverActivity but my logs on it, never get printed neither my break points get hit. But my logs on BrowserActivity get printed and my break points get hit 🙃

2019-02-27 20:58:43.877 1187-4749/? I/ActivityManager: START u0 {act=android.intent.action.VIEW dat=https://t.co/... flg=0x10000000 cmp=org.mozilla.reference.browser/.IntentReceiverActivity (has extras)} from uid 10184

A video when the issue happens and we press a different link from the one that caused the issue. it looks like ActivityManager is sending the same intent for just that link.

[Amejia481]

@pocmo as you have more experience with custom tabs what do you think?

What can we do from here?
We have to notify the Twitter android dev about the issue, because only Chrome and FireFox are going to be able to use custom tabs on their app.

To mitigate the issue, we could add a double check condition on BrowserActivity to verify if we have an intent that hasn't been processed by intentProcessor we have to process it.

[Amejia481]

STR:

1. Install custom tabs provider app.
2. Set as default browser.
3. Click link in Twitter app.
4. Observe 'CT intent unavailable' toast.
5. Change package name to a trusted browser package id (e.g. 'org.mozilla.firefox')
6. Observe that CT intent is accepted and page loads.

[jonalmeida]

There are a couple of linked issues here that are related and can possibly make the situation better if fixed.

[jonalmeida]

they are not including the extra flag CustomTabsIntent.EXTRA_SESSION android.support.customtabs.extra.SESSION

To clarify, the calling app doesn't set this extra, the support library does this when a CustomTab intent is created and sent.