facebook / facebook-android-sdk

Used to integrate Android apps with Facebook Platform.
https://developers.facebook.com/docs/android
Other
6.07k stars 3.64k forks source link

Invalid APP_EVENTS warning log #1222

Open andriishpek-sigma opened 6 months ago

andriishpek-sigma commented 6 months ago

Checklist before submitting a bug report

Java version

17.0.7

Android version

API 33

Android SDK version

16.2.0

Installation platform & version

Gradle 8.1

Package

Core & AppEvents

Goals

Fix invalid APP_EVENTS warning log for AppEventsLogger.activateApp(...) call.

Expected results

Fix invalid APP_EVENTS warning log for AppEventsLogger.activateApp(...) call.

Actual results

I'm using Facebook app events. When I frequently reopen the app, I get this log: Warning: Please call AppEventsLogger.activateApp(...)from the long-lived activity's onResume() methodbefore logging other app events.

I use AppEventsLogger.newLogger(this) inside Application.onCreate() to initialize the SDK.

Having dug the code, I realized that:

  1. Warning is logged in AppEventsLoggerImpl.logEvent(event: AppEvent, accessTokenAppId: AccessTokenAppIdPair)
  2. It happens because isActivateAppEventRequested = false
  3. isActivateAppEventRequested is set to true when event EVENT_NAME_ACTIVATED_APP is logged
  4. EVENT_NAME_ACTIVATED_APP is logged from SessionLogger.logActivateApp()
  5. SessionLogger.logActivateApp() is called from ActivityLifecycleTracker inside onActivityResumed() method when either there is no session currentSession = null, or suspendTime > sessionTimeoutInSeconds * 1000

Here's where the party comes. First of all, currentSession is always fetched from storage as soon as activity is created:

@JvmStatic
  fun onActivityCreated(activity: Activity?) {
    singleThreadExecutor.execute {
      if (currentSession == null) {
        currentSession = getStoredSessionInfo()
      }
    }
  }

When it comes to onActivityResumed(), currentSession is going to be null if and only if you've just installed the app. Otherwise, it'll be always loaded from storage inside onActivityCreated().

As per second condition: suspendTime > sessionTimeoutInSeconds * 1000. The default value of sessionTimeoutInSeconds is 60. suspendTime seems to be a duration since the last event was logged. So we can say that SDK 'throttles' logActivateApp() call if one was made during the last minute. Sounds legit: we want to treat current user session as the last one ended in past minute. However, that's where the issue happens: we've restored the previous session, but EVENT_NAME_ACTIVATED_APP was not logged, and AppEventsLogger.isActivateAppEventRequested = false, and logEvent() prints this warning.

It seems like if we throttle app activation, then we need to explicitly set AppEventsLogger.isActivateAppEventRequested to true.

Steps to reproduce

Precondition: Enable APP_EVENTS logging

  1. Open the app with Facebook app events enabled
  2. Give a few seconds for SDK to initialize; log some events; all works fine
  3. Close and open the app within one minute
  4. Log some more events

ER: There is no warning in logcat about app initialization. AR: There is a warning in logcat: "Warning: Please call AppEventsLogger.activateApp(...)from the long-lived activity's onResume() methodbefore logging other app events.". It it logged right after each and every event is logged into SDK.

Code samples & details

No response