[iOS] Interactive Notification Background Coldstart Callback Not Triggered

[ucswift]

Great work on the plugin guys, really happy to see iOS Interactive Notifications. I've been trying to get background processing of Interactive Notifications working on iOS, but have run into a wall when trying to process background notifications during a coldstart operation (app not in memory). When the app is in memory the callbacks are triggered without issue. Once the notification is received and the user interacts with it the callback isn't processed until the user activates the app.

I've been testing on iOS 8.4 and 9.2 (iPhone 6+ and an iPad Air 2) utilizing the 1.5.3 version of the plugin.

Here is my JS for registration:
var iosConfig = {
"badge": "true",
"sound": "true",
"alert": "true",
"clearBadge": "true",
"categories": {
"CALLS": {
"yes": {
"callback": "pushActionResponding", "title": "Resp", "foreground": false, "destructive": false
},
"no": {
"callback": "pushActionNotResponding", "title": "Not Resp", "foreground": false, "destructive": true
}
}
}
};

            window.pushPlugin = PushNotification.init({
                "android": androidConfig,
                "ios": iosConfig,
                "windows": wp8Config
            });

            window.pushPlugin.on('registration', pushRegisteredEvent);
            window.pushPlugin.on('notification', pushOnNotificationEvent);

Here is the JSON for the push:
{"aps" : { "alert" : "Push Notification Message", "content-available": 1, "category" : "CALLS", "badge" : 1, "sound" : "callFile.caf" }, "eventCode": "C1000" }

Here is a XCode dump of the app state. I've added a break when I manually activated the app and the callback was processed.

Jan 31 18:27:00 Shawns-iPhone6 kernel[0] : IOReturn IOAsynchronousScheduler::checkAndQueueArgument(IOAsynchronousScheduler::ArgumentEntry *): max argument count (128) reached. Notify a few first.
Jan 31 18:27:02 Shawns-iPhone6 SpringBoard[57] : The view controller <SBBulletinRootViewController: 0x156674a90> returned NO from -shouldAutorotateToInterfaceOrientation: for all interface orientations. It should support at least one orientation.
Jan 31 18:27:05 Shawns-iPhone6 kernel[0] : xpcproxy[8482] Container: /private/var/mobile/Containers/Data/Application/7444AFC0-D5F9-4151-9632-1A2203245F55 (sandbox)
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : assertion failed: 12H143: libxpc.dylib + 71768 [C9F3C08A-8A3B-3849-A905-D24911240853]: 0x7d
Jan 31 18:27:05 Shawns-iPhone6 Unknown[8482] :
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : Apache Cordova native platform version 3.8.0 is starting.
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : Multi-tasking -> Device: YES, App: YES
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : Unlimited access to network resources
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : [CDVTimer][statusbar] 31.412959ms
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : [CDVTimer][file] 3.073037ms
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : [CDVTimer][statusbar] 0.011981ms
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : [CDVTimer][uniquedeviceid] 0.059962ms
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : [CDVTimer][threedeetouch] 0.057042ms
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : [CDVTimer][splashscreen] 7.474005ms
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : [CDVTimer][TotalPluginStartup] 43.322027ms
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : Push Plugin handleActionWithIdentifier pushActionResponding
Jan 31 18:27:05 Shawns-iPhone6 Cordova400[8482] : Notification received
Jan 31 18:27:06 Shawns-iPhone6 kernel[0] : IOReturn IOAsynchronousScheduler::checkAndQueueArgument(IOAsynchronousScheduler::ArgumentEntry *): max argument count (128) reached. Notify a few first.

===================THEN NOTHING TILL I MANUALLY ACTIVATE THE APP===================

Jan 31 18:27:38 Shawns-iPhone6 Cordova400[8482] : Resetting plugins due to page load.
Jan 31 18:27:38 Shawns-iPhone6 Cordova400[8482] : active
Jan 31 18:27:38 Shawns-iPhone6 Cordova400[8482] : PushPlugin skip clear badge
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : OPEN database: ResgridResponder
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Initializing SQLitePlugin
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Detected docs path: /var/mobile/Containers/Data/Application/7444AFC0-D5F9-4151-9632-1A2203245F55/Documents
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Detected Library path: /var/mobile/Containers/Data/Application/7444AFC0-D5F9-4151-9632-1A2203245F55/Library
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : no cloud sync at path: /var/mobile/Containers/Data/Application/7444AFC0-D5F9-4151-9632-1A2203245F55/Library/LocalDatabase
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : new transaction is waiting for open operation
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : open full db path: /var/mobile/Containers/Data/Application/7444AFC0-D5F9-4151-9632-1A2203245F55/Documents/ResgridResponder
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : NOTIFY: Register for push called
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : ERROR: Plugin 'PushPlugin' not found, or is not a CDVPlugin. Check your plugin mapping in config.xml.
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Good news: SQLite is thread safe!
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : DB opened: ResgridResponder
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Push Plugin register called
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : PushPlugin.register: setting badge to true
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : PushPlugin.register: clear badge is set to 1
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : PushPlugin.register: better button setup
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : categories: key CALLS
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Adding category CALLS
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Finished load of: file:///var/mobile/Containers/Data/Application/7444AFC0-D5F9-4151-9632-1A2203245F55/Documents/index.html#/app/splash
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : GCM Sender ID (null)
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Using APNS Notification
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Notification received
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Push Plugin key: sound
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Push Plugin key: content-available
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Push Plugin key: alert
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Push Plugin key: category
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Push Plugin key: badge
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Interactive Push: Responding Callback
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Push Plugin finish called
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Push Plugin register success: <e19b987e 20a38e76 0baf5756 79b35604 4ee74ea0 f2664683 bb85b286 d3c55fa8>
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : push registration event
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : {"registrationId":"e19b987e20a38e760baf575679b356044ee74ea0f2664683bb85b286d3c55fa8"}
Jan 31 18:27:40 Shawns-iPhone6 Cordova400[8482] : Registering IOS/Android Notification

[goodthing]

I'm not sure if this is the same issue or not
When I tried in both ANDROID and IOS, clicking on the push notification while the app is completely closed does not trigger the onNotification after the app is opened.

I saw there are a few issues that may be similar but can't decide which one it really is. I'm not really looking to run some processes if the user does not click on the notification, only that when they do click it I need to know which notification it came from to redirect to the right screen.

[jopelkey]

@macdonst Since you closed my #576 issue as a duplicate of this, I spent a little time verifying that they do indeed seem to be related. And, yes, the action button callbacks that are not getting invoked for me as reported in issue #576, do indeed end up getting called it I open the app.

Just as an FYI, I have the same callback code working successfully on Android with the 1.6.x branch of the plugin (thanks!). I am anxious to see this working on IOS as well. Since we have our app ready to go with that fix when it's available, I want to let you know that we can help verify that fix in the context of our app if that is helpful to you. We can run some pretty quick sanity checks on an Iphone 4 (running IOS 9.1), an iphone 5 (running IOS 9.2.1), and an iphone 6 (also running 9.2.1). Just let me know.

[jopelkey]

I am trying to verify that my IOS action button callbacks work now that you have checked in code here.
I am able to get my yes callback called the first time now, but on the second push when I select the yes action button again, I am getting this error:

2016-03-01 17:01:49.484 Mobile Auth[344:199013] Warning: Application delegate received call to -application:handleActionWithIdentifier:forRemoteNotification:completionHandler: but the completion handler was never called.

*My setup is the same as it was for issue #576... repeated here:
*
I am using:

Xcode 7.2
IOS 9.2.1 on an Iphone 5
cordova cli: 6.0.0
cordova-ios: 4.0.1
phonegap-plugin-push: 1.6.x

I have my callbacks defined like:

window.acceptVerification = function(data) {
console.log('PushService: handle Accept Verification Button');
console.log("ACCEPT DATA: " + JSON.stringify(data));
}
window.rejectVerification = function(data) {
console.log('PushService: handle Reject Verification Button');
console.log("REJECT DATA: " + JSON.stringify(data));
}

and my init config looks like:

config = {
"ios" : {
"badge": "true",
"clearBadge": "true",
"sound": "true",
"alert": "true",
"categories": {
"verification": {
"yes": {
"callback": "window.acceptVerification",
"title": "Accept",
"foreground": false,
"destructive": false
},
"no": {
"callback": "window.rejectVerification",
"title": "Reject",
"foreground": false,
"destructive": true
}
}
}
}
}

*_Here's the push plugin output from my log:
*_2016-03-01 17:01:20.857 Mobile Auth[344:199013] createNotificationChecker
2016-03-01 17:01:20.857 Mobile Auth[344:199013] not coldstart
2016-03-01 17:01:20.859 Mobile Auth[344:199013] active
2016-03-01 17:01:20.860 Mobile Auth[344:199013] PushPlugin skip clear badge

2016-03-01 17:01:22.025 Mobile Auth[344:199050] Push Plugin register called
2016-03-01 17:01:22.025 Mobile Auth[344:199050] PushPlugin.register: setting badge to true
2016-03-01 17:01:22.026 Mobile Auth[344:199050] PushPlugin.register: clear badge is set to 1
2016-03-01 17:01:22.026 Mobile Auth[344:199050] PushPlugin.register: better button setup
2016-03-01 17:01:22.026 Mobile Auth[344:199050] categories: key verification
2016-03-01 17:01:22.028 Mobile Auth[344:199050] Adding category verification
2016-03-01 17:01:22.028 Mobile Auth[344:199050] GCM Sender ID (null)
2016-03-01 17:01:22.029 Mobile Auth[344:199050] Using APNS Notification
2016-03-01 17:01:22.054 Mobile Auth[344:199013] Push Plugin register success: <78c1c0d3 30953475 4c21a762 13e3adae d541081c 68952c27 8fcb507e 7f42b4f3>

2016-03-01 17:01:39.867 Mobile Auth[344:199013] Push Plugin handleActionWithIdentifier window.acceptVerification
2016-03-01 17:01:39.867 Mobile Auth[344:199013] Notification received
2016-03-01 17:01:39.868 Mobile Auth[344:199013] Push Plugin key: sound
2016-03-01 17:01:39.868 Mobile Auth[344:199013] Push Plugin key: alert
2016-03-01 17:01:39.868 Mobile Auth[344:199013] Push Plugin key: category
2016-03-01 17:01:39.868 Mobile Auth[344:199013] Push Plugin key: badge

2016-03-01 17:01:49.483 Mobile Auth[344:199013] Push Plugin handleActionWithIdentifier window.acceptVerification
2016-03-01 17:01:49.484 Mobile Auth[344:199013] Warning: Application delegate received call to -application:handleActionWithIdentifier:forRemoteNotification:completionHandler: but the completion handler was never called.
2016-03-01 17:01:49.487 Mobile Auth[344:199013] Notification received
2016-03-01 17:01:49.488 Mobile Auth[344:199013] Push Plugin key: sound
2016-03-01 17:01:49.488 Mobile Auth[344:199013] Push Plugin key: alert
2016-03-01 17:01:49.488 Mobile Auth[344:199013] Push Plugin key: category
2016-03-01 17:01:49.488 Mobile Auth[344:199013] Push Plugin key: badge

[macdonst]

@jopelkey you need to call push.finish in your callbacks. So:

window.acceptVerification = function(data) {
  console.log('PushService: handle Accept Verification Button'); 
  console.log("ACCEPT DATA: " + JSON.stringify(data));
  push.finish(function() {
    console.log('accept finished');
  });
}
window.rejectVerification = function(data) {
  console.log('PushService: handle Reject Verification Button');
  console.log("REJECT DATA: " + JSON.stringify(data));
  push.finish(function() {
    console.log('reject finished');
  });
}

Try that and let me know as there still may be bugs.

[jopelkey]

Unfortunately, even with the push.finish() call in there I still get the same error:

2016-03-01 17:38:26.407 Mobile Auth[374:205780] Push Plugin handleActionWithIdentifier window.acceptVerification
2016-03-01 17:38:26.408 Mobile Auth[374:205780] Notification received
2016-03-01 17:38:26.408 Mobile Auth[374:205780] Push Plugin key: sound
2016-03-01 17:38:26.408 Mobile Auth[374:205780] Push Plugin key: alert
2016-03-01 17:38:26.408 Mobile Auth[374:205780] Push Plugin key: category
2016-03-01 17:38:26.409 Mobile Auth[374:205780] Push Plugin key: badge
2016-03-01 17:38:26.421 Mobile Auth[374:205780] PushService: handle Accept Verification Button

2016-03-01 17:38:26.421 Mobile Auth[374:205780] Push Plugin finish called
2016-03-01 17:38:26.440 Mobile Auth[374:205780] accept finished
2016-03-01 17:38:42.466 Mobile Auth[374:205780] Push Plugin handleActionWithIdentifier window.acceptVerification
2016-03-01 17:38:42.466 Mobile Auth[374:205780] Warning: Application delegate received call to -application:handleActionWithIdentifier:forRemoteNotification:completionHandler: but the completion handler was never called.
2016-03-01 17:38:42.467 Mobile Auth[374:205780] Notification received
2016-03-01 17:38:42.467 Mobile Auth[374:205780] Push Plugin key: sound
2016-03-01 17:38:42.468 Mobile Auth[374:205780] Push Plugin key: alert
2016-03-01 17:38:42.468 Mobile Auth[374:205780] Push Plugin key: category
2016-03-01 17:38:42.468 Mobile Auth[374:205780] Push Plugin key: badge

[macdonst]

@jopelkey are you sending two messages and clicking there buttons one after another?

[macdonst]

@jopelkey the logs should look like:

2016-03-01 20:44:31.346 Push151[4457:1902928] Push Plugin register called
2016-03-01 20:44:31.346 Push151[4457:1902928] PushPlugin.register: setting badge to false
2016-03-01 20:44:31.347 Push151[4457:1902928] PushPlugin.register: clear badge is set to 0
2016-03-01 20:44:31.347 Push151[4457:1902928] PushPlugin.register: better button setup
2016-03-01 20:44:31.347 Push151[4457:1902928] categories: key delete
2016-03-01 20:44:31.347 Push151[4457:1902928] Adding category delete
2016-03-01 20:44:31.347 Push151[4457:1902928] categories: key invite
2016-03-01 20:44:31.347 Push151[4457:1902928] Adding category invite
2016-03-01 20:44:31.357 Push151[4457:1902928] GCM Sender ID (null)
2016-03-01 20:44:31.357 Push151[4457:1902928] Using APNS Notification
2016-03-01 20:44:31.362 Push151[4457:1902908] Push Plugin register success: <registration ID>
2016-03-01 20:45:17.696 Push151[4457:1902908] Push Plugin handleActionWithIdentifier app.reject
2016-03-01 20:45:17.697 Push151[4457:1902908] Notification received
2016-03-01 20:45:17.697 Push151[4457:1902908] Push Plugin key: alert
2016-03-01 20:45:17.698 Push151[4457:1902908] Push Plugin key: badge
2016-03-01 20:45:17.698 Push151[4457:1902908] Push Plugin key: category
2016-03-01 20:45:17.709 Push151[4457:1902908] Push Plugin finish called
2016-03-01 20:45:37.812 Push151[4457:1902908] Push Plugin stopBackgroundTask called
2016-03-01 20:45:37.814 Push151[4457:1902908] Push Plugin handlerObj
2016-03-01 20:45:37.816 Push151[4457:1902908] Push Plugin: stopBackgroundTask (remaining t: 9.871679)

[jopelkey]

@macdonst Yes - I am sending 2 pushes one after the other. I send push 1, choose the Accept button, after seeing my 'accept finished' logging I send push 2, and then choose Accept again. At that point I see the completionHandler warning.

After peeking at the code it looks like the completion handler isn't getting called for a full 20 seconds after my push.finish() completes. I see that pause in your log above as well. Turns out I have been sending my second push and choosing Accept again within that 20 second window and that's when I get the completionHandler not called warning. If I wait the full 20 seconds, then I do indeed get the stopBackgroundTask logging and the second push/Accept works.

Is there a reason for that 20 second pause?

[macdonst]

@jopelkey your findings are the same as mine. Trying to figure out how to fix it.

[macdonst]

@jopelkey okay, I think I've got a solution. It's not particularly elegant but it seems to be working. Check the docs I wrote along with the above commit. Please let me know if they don't make sense. I've been able to get multiple pushes with action buttons working with this new approach.

[jopelkey]

@macdonst So close... I am able to send multiple pushes in a row and use the action buttons now on my happy path processing. However, on my error path, I am still having issues. We are using local notifications in the case where we encounter an issue during background processing, and if I schedule a local notification, then call push.finish(), I see 2 issues:

1. the stopBackgroundTask is back to waiting for 20 seconds before it is called
2. on the second push I send (whether I wait for the 20 seconds or not), subsequent pushes do not show the action buttons at all!

The local notification plugin is this one:
https://github.com/katzer/cordova-plugin-local-notifications#0.8.4
And I am using the ngCordova 0.1.24-alpha wrapper around it.

My invocation to schedule that local notification just looks like this:
var localNotifOptions = {
id: 0,
title: title,
text: msg
};
$cordovaLocalNotification.schedule(localNotifOptions);

Here's my full logging from a run with this issue:

2016-03-05 06:07:05.977 Mobile Auth[961:728218] createNotificationChecker
2016-03-05 06:07:05.977 Mobile Auth[961:728218] not coldstart
2016-03-05 06:07:05.980 Mobile Auth[961:728218] active
2016-03-05 06:07:05.980 Mobile Auth[961:728218] PushPlugin skip clear badge

Here's my push config:

2016-03-05 06:07:07.017 Mobile Auth[961:728218] PushSvc: init config:
{"ios":{"badge":"true","clearBadge":"true","sound":"true","alert":"true","categories":{"verification":{"yes":{"callback":"window.acceptVerification","title":"Verify","foreground":false,"destructive":false},"no":{"callback":"window.rejectVerification","title":"Reject","foreground":false,"destructive":true}}}}}

2016-03-05 06:07:07.030 Mobile Auth[961:728256] Push Plugin register called
2016-03-05 06:07:07.031 Mobile Auth[961:728256] PushPlugin.register: setting badge to true
2016-03-05 06:07:07.031 Mobile Auth[961:728256] PushPlugin.register: clear badge is set to 1
2016-03-05 06:07:07.031 Mobile Auth[961:728256] PushPlugin.register: better button setup
2016-03-05 06:07:07.031 Mobile Auth[961:728256] categories: key verification
2016-03-05 06:07:07.031 Mobile Auth[961:728256] Adding category verification
2016-03-05 06:07:07.032 Mobile Auth[961:728256] GCM Sender ID (null)
2016-03-05 06:07:07.032 Mobile Auth[961:728256] Using APNS Notification

Here's where the first push/action button handling happens:

Here's where the first push/action button handling happens:

2016-03-05 06:07:23.222 Mobile Auth[961:728218] Push Plugin handleActionWithIdentifier window.acceptVerification
2016-03-05 06:07:23.223 Mobile Auth[961:728218] Push Plugin userInfo {
aps = {
alert = {
body = "Some tenant name\nLogin Verification\nsome.tenant.com";
};
badge = 2;
category = verification;
sound = default;
};
callback = "window.acceptVerification";
notId = "NOTID-1457183250";
pushPayload = {
authenticatorId = authId;
request = {
loginUri = "sendMsg.fake.com";
requestId = 4330079;
requestTimestamp = 1457183250;
responseUri = responseUri;
tenantId = tenantId;
tenantName = "sendMsg.js fake tenant";
uri = uri;
userId = userId;
};
};
}
2016-03-05 06:07:23.223 Mobile Auth[961:728218] Notification received
2016-03-05 06:07:23.226 Mobile Auth[961:728218] Push Plugin key: sound
2016-03-05 06:07:23.226 Mobile Auth[961:728218] Push Plugin key: alert
2016-03-05 06:07:23.227 Mobile Auth[961:728218] Push Plugin key: badge
2016-03-05 06:07:23.227 Mobile Auth[961:728218] Push Plugin key: category
2016-03-05 06:07:23.276 Mobile Auth[961:728218] PushSvc: clear badge count: app badge count set to 0
2016-03-05 06:07:23.796 Mobile Auth[961:728218] PushSvc: finish notId: NOTID-1457183250

Here I send a local notification using the other plugin.
I tried making the local notification schedule call both before I call push.finish and inside the push.finish callback, but I see the same behavior either way, I do make it into to the push.finish success callback.

2016-03-05 06:07:23.817 Mobile Auth[961:728218] PushSvc: Local Notification Options: {"id":0,"title":"Verification Issue","text":"Enter app to retry."}

Note the 20 second lag here still:

2016-03-05 06:07:43.809 Mobile Auth[961:728218] Push Plugin stopBackgroundTask called
2016-03-05 06:07:43.809 Mobile Auth[961:728218] Push Plugin handlerObj
2016-03-05 06:07:43.812 Mobile Auth[961:728218] Push Plugin: stopBackgroundTask (remaining t: 9.400138)

I send a 2nd push here: there's no more logging since it doesn't have any action buttons shown

[macdonst]

@jopelkey I just dropped the delay down from 20 seconds to 0.1 seconds. Can you give that a try?

[jopelkey]

@macdonst Well, that got rid of the 20 second lag in that scenario, but I still have the issue where the second push no longer has any action buttons on it.

[macdonst]

@jopelkey I'm going to release 1.6.0 but I want to fix your problem. Can you open a new issue with the specifics of your current issue and we'll bump a 1.6.1 when it's fixed?

[jopelkey]

@macdonst As requested I filed a new issue #682

[lock]

This thread has been automatically locked.