Onesignal-android-sdk: OneSignal.addSubscriptionObserver not called until the app is launched again

Created on 30 Apr 2019 · 15Comments · Source: OneSignal/OneSignal-Android-SDK

Description:

OneSignal.addSubscriptionObserver is not called until app is launched again. It should be called at the moment the SDK receives the user ID.

I setup the SDK and after initializing it I add this observer:

OneSignal.addSubscriptionObserver { stateChanges: OSSubscriptionStateChanges ->
    Timber.d("OneSignal - addSubscriptionObserver stateChanges: $stateChanges")
}

At the very first app installation ever I see this:

OneSignal - addSubscriptionObserver stateChanges: {"from":{"userId":null,"pushToken":null,"userSubscriptionSetting":false,"subscribed":false},"to":{"userId":null,"pushToken":null,"userSubscriptionSetting":true,"subscribed":false}}

After this the subscription/registration is properly done, as I see this on the OneSignal SDK logs:

2019-04-30 12:16:30.526 27961-28052/com.gazella.debug D/OneSignal: registerUser: registerForPushFired:true, locationFired: true, remoteParams: com.onesignal.OneSignalRemoteParams$2@3e0824c
2019-04-30 12:16:35.685 27961-28118/com.gazella.debug D/OneSignal: OneSignalRestClient: Making request to: https://onesignal.com/api/v1/players
2019-04-30 12:16:35.690 27961-28118/com.gazella.debug D/OneSignal: OneSignalRestClient: POST SEND JSON: {"app_id":"7fa5258e-f87f-4951-9f20-3cf5217ca2a8","ad_id":"79b51931-66d6-4a75-b50f-0ef727101431","device_os":"9","timezone":7200,"language":"ca","sdk":"031008","sdk_type":"native","android_package":"com.gazella.debug","device_model":"ONEPLUS A5010","game_version":23,"pkgs_a":["BKH13cThxtD0spwaR+jw2\/VtMwOZW9zk1uAxGv600AE=","ggkiwg4joSMCxEwKwJeXYB6P5pim81rynLOLua10MXw=","4ufw23+D\/fbncwfHbFIXHZnKE\/2AeKBEI\/cZdEAxCAg=","h3EerLf\/YWdwD9g9F9JpIC2iGNi1CIV33gQkvGNByoo="],"net_type":0,"carrier":"Tuenti","rooted":false,"identifier":"cackAXnF4BA:APA91bG3ds80vCjEGN5wyQ-WT931I_dx-KOsrfzf7ze3otlEa2oivC9VnrDNfjTlIHFTOMMvyfBvlAEoq9QV7zWUe7akEkjyPY-9y1n9itwjokVoW5mtgupP2kMFAQ9JoU7WVnbM-0HE","device_type":1}
2019-04-30 12:16:35.976 27961-28118/com.gazella.debug D/OneSignal: OneSignalRestClient: Successfully finished request to: https://onesignal.com/api/v1/players
2019-04-30 12:16:35.983 27961-28118/com.gazella.debug D/OneSignal: OneSignalRestClient: POST RECEIVED JSON: {"success":true,"id":"2adb5e4b-eb7a-47f9-a438-39f642db15cb"}
2019-04-30 12:16:36.019 27961-28121/com.gazella.debug I/OneSignal: Device registered, UserId = 2adb5e4b-eb7a-47f9-a438-39f642db15cb

However the observer is not triggered. Then I close and run the app for a 2nd time and I see that the observer is triggered reporting the subscription that was done before I closed the app:

OneSignal - addSubscriptionObserver stateChanges: {"from":{"userId":null,"pushToken":null,"userSubscriptionSetting":true,"subscribed":false},"to":{"userId":"2adb5e4b-eb7a-47f9-a438-39f642db15cb","pushToken":"fuj9_cPMDy8:APA91bFb12uePuJ2_q0G-Eooyu-Tt1zco6mpLB0VD-2iw_877SnMLi2DhYJ401EIvbJBntOvp_Ka7WntQRUfDcGb0yop_ZJIR5co-mS-UP7wVrzSbBUW0gHvQN8R9QiS8pOEzES1-Bqu","userSubscriptionSetting":true,"subscribed":true}}

There is no point on having this observer if it's not called immediately when the subscription is done. I want to send the user ID to my server at the moment it's received, not when the user opens the app again some days later.

Environment

Using OneSignal 3.10.8 like this: implementation 'com.onesignal:OneSignal:3.10.8'

Steps to Reproduce Issue:

Uninstall app and then run it for very first time. The registration is done but the observer is not triggered.

Close app and launch again. The observer is triggered.

Anything else:

(crash stacktraces, as well as any other information here)

I've added the complete logs below.

Help Wanted Non-Reproducible

Source

AlbertVilaCalvo

👍4

Most helpful comment

I am getting the following on the first install:
{"from":{"userId":null,"pushToken":null,"userSubscriptionSetting":false,"subscribed":false},"to":{"userId":null,"pushToken":null,"userSubscriptionSetting":true,"subscribed":false}}

Instead of using the observer, consider using the idsAvailable method. I just realized there is no documentation on that. Will go ahead and add it. Sorry about that!

EDIT
Actually, it looks like idsAvailable is deprecated in favor of addSubscriptionObserver. It is still a part of the SDK however so it might be worth a shot since its closer to what you're looking for. Just keep in mind it is deprecated.

In either case, for me, I don't have to relaunch the app to trigger the observer. It just takes a couple of seconds to receive the id from OneSignal. Once it does, you should see something like:

{"from":{"userId":null,"pushToken":"<push token>","userSubscriptionSetting":true,"subscribed":false},"to":{"userId":"b2f4a746-93c3-4ad4-bc7b-04ab2b5f9d71","pushToken":"<push token>","userSubscriptionSetting":true,"subscribed":true}}

Take a look at my own logs here. You will see that the onOSPermissionChanged log appears twice early on.

My example code below:
```java
public class ExampleApplication extends Application {

@Override
public void onCreate() {
super.onCreate();
// Logging set to help debug issues, remove before releasing your app.
OneSignal.setLogLevel(OneSignal.LOG_LEVEL.VERBOSE, OneSignal.LOG_LEVEL.WARN);

  OneSignal.startInit(this)
          .setNotificationReceivedHandler(new ExampleNotificationReceivedHandler())
          .setNotificationOpenedHandler(new ExampleNotificationOpenedHandler())
          .inFocusDisplaying(OneSignal.OSInFocusDisplayOption.Notification)
          .unsubscribeWhenNotificationsAreDisabled(true)
          .init();

  OneSignal.addSubscriptionObserver(mSubscriptionObserver);

}

private OSSubscriptionObserver mSubscriptionObserver = new OSSubscriptionObserver() {

  @Override
  public void onOSSubscriptionChanged(OSSubscriptionStateChanges stateChanges) {
     Log.d("Rodrigo", "onOSPermissionChanged: " + stateChanges);
     if (!stateChanges.getFrom().getSubscribed() &&
             stateChanges.getTo().getSubscribed()) {
        // get player ID
        String oneSignalID = stateChanges.getTo().getUserId();
        // send oneSignalID to server
     }
  }

};```

rgomezp on 30 May 2019

👍2

All 15 comments

Additional info

These are the complete logs (the OneSignal logs and my log at the observer) of the first time I open the app:

2019-04-30 12:21:30.240 28382-28382/? D/OneSignal: registerUser: registerForPushFired:false, locationFired: true, remoteParams: null
2019-04-30 12:21:30.240 28382-28382/? D/OneSignal: Starting request to get Android parameters.
2019-04-30 12:21:30.246 28382-28382/? D/PushSetup$execute: OneSignal - addSubscriptionObserver stateChanges: {"from":{"userId":null,"pushToken":null,"userSubscriptionSetting":false,"subscribed":false},"to":{"userId":null,"pushToken":null,"userSubscriptionSetting":true,"subscribed":false}}
2019-04-30 12:21:30.249 28382-28446/? D/OneSignal: OneSignalRestClient: Making request to: https://onesignal.com/api/v1/apps/7fa5258e-f87f-4951-9f20-3cf5217ca2a8/android_params.js
2019-04-30 12:21:30.403 28382-28446/com.gazella.debug D/OneSignal: OneSignalRestClient: Successfully finished request to: https://onesignal.com/api/v1/apps/7fa5258e-f87f-4951-9f20-3cf5217ca2a8/android_params.js
2019-04-30 12:21:30.422 28382-28446/com.gazella.debug D/OneSignal: OneSignalRestClient: GET RECEIVED JSON: {"awl_list":{"T6K1NaiarCa+uMYbmkfwKK7c+CH57ZV32bMa0NAE3Yw=":1...
(omitted bunch of characters for brevity)
2019-04-30 12:21:30.426 28382-28446/com.gazella.debug D/OneSignal: OneSignalRestClient: Response has etag of W/"f546fe39bc232fa25a0f9ccca34cda96" so caching the response.
2019-04-30 12:21:30.618 28382-28382/com.gazella.debug D/OneSignal: curActivity is NOW: com.gazella.ui.landing.LandingActivity:com.gazella.ui.landing.LandingActivity@cf31dc2
2019-04-30 12:21:30.621 28382-28472/com.gazella.debug I/OneSignal: Restoring notifications
2019-04-30 12:21:30.661 28382-28472/com.gazella.debug I/OneSignal: Querying DB for notifs to restore: created_time > 1556014890 AND dismissed = 0 AND opened = 0 AND is_summary = 0 AND expire_time > 1556619690
2019-04-30 12:21:30.916 28382-28461/com.gazella.debug I/OneSignal: Device registered, push token = dSrE9zIHNIs:APA91bEOc21afy3i3JXTk_jj_zFj2TOX36RAp2xOFw_jZTp-tLFKT7b0OjXVno56-Y8iHTeV0s0s4jE1RkFhdX8tP0pfuAoTzlCfRM2KHzStORTVnNIkJ-3ZaxyYs_895eY74ypl2aN4
2019-04-30 12:21:30.916 28382-28461/com.gazella.debug D/OneSignal: registerUser: registerForPushFired:true, locationFired: true, remoteParams: com.onesignal.OneSignalRemoteParams$2@e2acee4
2019-04-30 12:21:36.036 28382-28531/com.gazella.debug D/OneSignal: OneSignalRestClient: Making request to: https://onesignal.com/api/v1/players
2019-04-30 12:21:36.040 28382-28531/com.gazella.debug D/OneSignal: OneSignalRestClient: POST SEND JSON: {"app_id":"7fa5258e-f87f-4951-9f20-3cf5217ca2a8","ad_id":"79b51931-66d6-4a75-b50f-0ef727101431","device_os":"9","timezone":7200,"language":"ca","sdk":"031008","sdk_type":"native","android_package":"com.gazella.debug","device_model":"ONEPLUS A5010","game_version":23,"pkgs_a":["BKH13cThxtD0spwaR+jw2\/VtMwOZW9zk1uAxGv600AE=","ggkiwg4joSMCxEwKwJeXYB6P5pim81rynLOLua10MXw=","4ufw23+D\/fbncwfHbFIXHZnKE\/2AeKBEI\/cZdEAxCAg=","h3EerLf\/YWdwD9g9F9JpIC2iGNi1CIV33gQkvGNByoo="],"net_type":0,"carrier":"Tuenti","rooted":false,"identifier":"dSrE9zIHNIs:APA91bEOc21afy3i3JXTk_jj_zFj2TOX36RAp2xOFw_jZTp-tLFKT7b0OjXVno56-Y8iHTeV0s0s4jE1RkFhdX8tP0pfuAoTzlCfRM2KHzStORTVnNIkJ-3ZaxyYs_895eY74ypl2aN4","device_type":1}
2019-04-30 12:21:36.330 28382-28531/com.gazella.debug D/OneSignal: OneSignalRestClient: Successfully finished request to: https://onesignal.com/api/v1/players
2019-04-30 12:21:36.344 28382-28531/com.gazella.debug D/OneSignal: OneSignalRestClient: POST RECEIVED JSON: {"success":true,"id":"2adb5e4b-eb7a-47f9-a438-39f642db15cb"}
2019-04-30 12:21:36.371 28382-28533/com.gazella.debug I/OneSignal: Device registered, UserId = 2adb5e4b-eb7a-47f9-a438-39f642db15cb

AlbertVilaCalvo on 30 Apr 2019

And the logs the 2nd time I open the app, in which the observer is notified that the subscription is done:

2019-04-30 12:29:06.947 28759-28759/com.gazella.debug D/PushSetup$execute: OneSignal - addSubscriptionObserver stateChanges: {"from":{"userId":null,"pushToken":null,"userSubscriptionSetting":true,"subscribed":false},"to":{"userId":"2adb5e4b-eb7a-47f9-a438-39f642db15cb","pushToken":"dSrE9zIHNIs:APA91bEOc21afy3i3JXTk_jj_zFj2TOX36RAp2xOFw_jZTp-tLFKT7b0OjXVno56-Y8iHTeV0s0s4jE1RkFhdX8tP0pfuAoTzlCfRM2KHzStORTVnNIkJ-3ZaxyYs_895eY74ypl2aN4","userSubscriptionSetting":true,"subscribed":true}}
2019-04-30 12:29:06.950 28759-28759/com.gazella.debug D/SharedPreferencesPushState: OneSignal - PushState.isPushRegisteredAtOurServer() is false
2019-04-30 12:29:07.273 28759-28759/com.gazella.debug D/OneSignal: curActivity is NOW: com.gazella.ui.landing.LandingActivity:com.gazella.ui.landing.LandingActivity@7caa09
2019-04-30 12:29:07.279 28759-28759/com.gazella.debug D/OneSignal: registerUser: registerForPushFired:false, locationFired: true, remoteParams: null
2019-04-30 12:29:07.280 28759-28759/com.gazella.debug D/OneSignal: Starting request to get Android parameters.
2019-04-30 12:29:07.286 28759-28845/com.gazella.debug D/OneSignal: OneSignalRestClient: Making request to: https://onesignal.com/api/v1/apps/7fa5258e-f87f-4951-9f20-3cf5217ca2a8/android_params.js?player_id=2adb5e4b-eb7a-47f9-a438-39f642db15cb
2019-04-30 12:29:07.289 28759-28845/com.gazella.debug D/OneSignal: OneSignalRestClient: Adding header if-none-match: W/"f546fe39bc232fa25a0f9ccca34cda96"
2019-04-30 12:29:07.289 28759-28846/com.gazella.debug I/OneSignal: Restoring notifications
2019-04-30 12:29:07.301 28759-28846/com.gazella.debug I/OneSignal: Querying DB for notifs to restore: created_time > 1556015347 AND dismissed = 0 AND opened = 0 AND is_summary = 0 AND expire_time > 1556620147
2019-04-30 12:29:07.433 28759-28845/com.gazella.debug D/OneSignal: OneSignalRestClient: GET - Using Cached response due to 304: {"awl_list":{"T6K1NaiarCa+uMYbmkfwKK7c+CH57ZV32bMa0NAE3Yw=":1,

AlbertVilaCalvo on 30 Apr 2019

Hello @AlbertVilaCampo ,
Could you please include your entire main block of code including the various OneSignal function calls?

rgomezp on 6 May 2019

This is what I'm doing in Application#onCreate:

if (BuildConfig.DEBUG) {
    OneSignal.setLogLevel(OneSignal.LOG_LEVEL.DEBUG, OneSignal.LOG_LEVEL.WARN)
}

OneSignal.startInit(application)
    .inFocusDisplaying(OneSignal.OSInFocusDisplayOption.Notification)
    .unsubscribeWhenNotificationsAreDisabled(true)
    .init()

OneSignal.addSubscriptionObserver { stateChanges: OSSubscriptionStateChanges ->
    Timber.d("OneSignal - addSubscriptionObserver stateChanges: $stateChanges")
    if (!stateChanges.from.subscribed && stateChanges.to.subscribed) {
        registerPushAtOurServer()
    }
}

In registerPushAtOurServer() I'm sending the OneSignal user ID to our server.

AlbertVilaCalvo on 7 May 2019

Hello @AlbertVilaCalvo ,
It looks correct. This may be a bug so we will have to reproduce it. Thank you for your patience.

rgomezp on 10 May 2019

👍1

Instead of using the observer, consider using the idsAvailable method. I just realized there is no documentation on that. Will go ahead and add it. Sorry about that!

In either case, for me, I don't have to relaunch the app to trigger the observer. It just takes a couple of seconds to receive the id from OneSignal. Once it does, you should see something like:

{"from":{"userId":null,"pushToken":"<push token>","userSubscriptionSetting":true,"subscribed":false},"to":{"userId":"b2f4a746-93c3-4ad4-bc7b-04ab2b5f9d71","pushToken":"<push token>","userSubscriptionSetting":true,"subscribed":true}}

Take a look at my own logs here. You will see that the onOSPermissionChanged log appears twice early on.

My example code below:
```java
public class ExampleApplication extends Application {

  OneSignal.startInit(this)
          .setNotificationReceivedHandler(new ExampleNotificationReceivedHandler())
          .setNotificationOpenedHandler(new ExampleNotificationOpenedHandler())
          .inFocusDisplaying(OneSignal.OSInFocusDisplayOption.Notification)
          .unsubscribeWhenNotificationsAreDisabled(true)
          .init();

  OneSignal.addSubscriptionObserver(mSubscriptionObserver);

}

private OSSubscriptionObserver mSubscriptionObserver = new OSSubscriptionObserver() {

  @Override
  public void onOSSubscriptionChanged(OSSubscriptionStateChanges stateChanges) {
     Log.d("Rodrigo", "onOSPermissionChanged: " + stateChanges);
     if (!stateChanges.getFrom().getSubscribed() &&
             stateChanges.getTo().getSubscribed()) {
        // get player ID
        String oneSignalID = stateChanges.getTo().getUserId();
        // send oneSignalID to server
     }
  }

};```

rgomezp on 30 May 2019

👍2

I've tried the idsAvailable and it works properly:

OneSignal.idsAvailable { userId: String, registrationId: String ->
    Timber.d("OneSignal - idsAvailable userId: $userId, registrationId $registrationId")
}

The log appears after

OneSignalRestClient: Successfully finished request to: https://onesignal.com/api/v1/players
OneSignalRestClient: POST RECEIVED JSON: {"success":true,"id":"2adb5e4b-eb7a-47f9-a438-39f642db15cb"}

which means that I could send the OneSignal ID in this listener.

However I still have to re-run the app to for the OSSubscriptionStateChanges to be called, which is wrong. I would like to send you the app code (privately) so that you can verify that this happens, but other people on the team don't want :(

BTW I forgot to say the version of the Gradle plugin we are using: classpath 'gradle.plugin.com.onesignal:onesignal-gradle-plugin:0.12.1'

AlbertVilaCalvo on 30 May 2019

Hello @AlbertVilaCalvo ,
I'm glad that idsAvailable is working as intended.

However I still have to re-run the app to for the OSSubscriptionStateChanges to be called, which is wrong.

Do you mean onOSPermissionChanged?

I would like to send you the app code (privately)

You can do this by reaching out through our support channel at http://onesignal.com (red bubble). We get projects sent to us all the time by our clients, though I totally understand if this is a concern

rgomezp on 4 Jun 2019

Closing due to no response

rgomezp on 13 Jun 2019

@rgomezp We are also facing the same issue, but I have a doubt here, if the user hasn't launched the app second time. Will the playerId will be synced to the OneSignal dashboard and be visible in the dashboard for sending notifications?

kunall17 on 6 Mar 2020

@rgomezp I had the same problem and your solution works.
But why if I do like that it doesn't work?
The only difference is that I don't have the mSubscriptionObserver in the class

` OneSignal.addSubscriptionObserver(new OSSubscriptionObserver() {

  @Override
  public void onOSSubscriptionChanged(OSSubscriptionStateChanges stateChanges) {
     Log.d("Rodrigo", "onOSPermissionChanged: " + stateChanges);
     if (!stateChanges.getFrom().getSubscribed() &&
             stateChanges.getTo().getSubscribed()) {
        // get player ID
        String oneSignalID = stateChanges.getTo().getUserId();
        // send oneSignalID to server
     }
  }

})
`

The onOSSubscriptionChanged function is called only once at the first launch and the userId is still null. If I use your solution then the handler is called two times and the second time the userId is set

dario30186 on 20 May 2020

This still isn't working on the latest version 4.0.0 idsAvailable method is removed from the newest version.
What's the current solution for this, since it wasn't fixed and workaround was removed?

gabrysgab on 18 Dec 2020

Howdy all,
Thanks for your patience.

@kunall17 ,
If the device successfully subscribes to push, it will be reflected in the dashboard as being successfully subscribed, regardless of any issue with the SDK reporting the status change via an observer firing.

@dario30186 ,
I'm glad this worked for you. We have since released version 4.0 of the SDK. This is a major release and includes breaking changes so you will want to follow our migration guide in our documentation.

@gabrysgab ,
That is correct. Since it was previously deprecated, we removed it completely in the new release. Can you please provide more information regarding your environment and repro steps? Please list things such as OS version, make, model, SDK version, etc...

rgomezp on 18 Dec 2020

Closing due to no response

rgomezp on 20 Jan 2021

Hello, why did you close this issue?
It still reproduced in v 4.2.0 of Onesignal SDK.
It's very esasy to reproduce it:

Add Android SDK in the app.
Call addSubscriptionObserver in the Application class.

Actual result: Called only once. Returns empty result:
{"from":{"userId":null,"pushToken":null,"isPushDisabled":true,"isSubscribed":false}, "to":{"userId":null,"pushToken":null,"isPushDisabled":false,"isSubscribed":false}}
Expected result: It should work like observer and called every time when something happens with observed data.

I see in logs that Onesignal initialized a bit later, but SubscriptionObserver called immediatly. I suppose It should be called one again after initialization.