Skip to content
This repository has been archived by the owner on Sep 4, 2020. It is now read-only.

Action button click callback not entirely executed #985

Closed
panaggio opened this issue Jun 14, 2016 · 22 comments
Closed

Action button click callback not entirely executed #985

panaggio opened this issue Jun 14, 2016 · 22 comments

Comments

@panaggio
Copy link

Expected Behaviour

On action button click, the action entire callback function (and any event callbacks that could happen as a consequence of it) should be executed when the app is not on foreground.

Actual Behaviour

Uncertain. Sometimes it executes the entire callback, sometimes it doesn't.

The worst part: on two sequential action button clicks, as the app isn't on foreground and a new event is added to the stack of events to be treated, the first event uses the little time that is available for the second to be executed. This leads to strange behavior in several cases.

Reproduce Scenario (including but not limited to)

Steps to Reproduce

This is easily reproducible if you do an HTTP request inside the callback, and do something inside the success/fail callback. Making the request to take long time makes it even easier.

Platform and Version (eg. Android 5.0 or iOS 9.2.1)

iOS 9.3.1

Cordova CLI version and cordova platform version

$ cordova --version
6.2.0
$ cordova platform version ios
Installed platforms:
browser 4.1.0
ios 4.1.1

Plugin version

$ cordova plugin version | grep phonegap-plugin-push
phonegap-plugin-push 1.6.4 "PushPlugin"

Sample Push Data Payload

Inside logs below.

Sample Code that illustrates the problem

function(data) {
    $.ajax({
        // ...
    }).always(function() {
        console.log('foo');
        instance.finish(success, error, notId)
    });
}

Logs taken while reproducing problem

2016-06-14 00:13:18.861 App Development Edition[376:59699] Push Plugin handleActionWithIdentifier App.push.approve
2016-06-14 00:13:18.862 App Development Edition[376:59699] Push Plugin userInfo {
    aps =     {
        alert =         {
            "loc-args" =             (
                ###
            );
            "loc-key" = "PUSH_BODY";
            "title-loc-args" =             (
                ###
            );
            "title-loc-key" = "PUSH_TITLE";
        };
        badge = 32;
        category = ar;
        "content-available" = 1;
        sound = default;
    };
    callback = "App.push.approve";
    document =     {
        ######
    };
    notId = 123456;
}
2016-06-14 00:13:18.869 App Development Edition[376:59699] Push Plugin notId 0000007019
2016-06-14 00:13:18.870 App Development Edition[376:59699] Warning: Application delegate received call to -application:didReceiveRemoteNotification:fetchCompletionHandler: but the completion handler was never called.
@panaggio
Copy link
Author

I have a theory on why this happens: iOS will move the application from suspended to background for a fixed amount of time, and that time is not enough for the entire callback to execute.

This could be/may be/is probably unrelated to the plugin. But maybe some docs could be added regarding this specific issue?

@macdonst
Copy link
Member

@panaggio how long does your callback take to execute? You should have approximately 30 seconds to execute in the background. Please read over the docs at https://github.com/phonegap/phonegap-plugin-push/blob/master/docs/PAYLOAD.md#background-notifications-1 and let me know where I can make things better.

@panaggio
Copy link
Author

I remember reading that but I wasn't able to find it. But that isn't the case (at least it's not happening): for the matter of debugging, now I'm doing a busy wait when the action button is clicked, for 30 seconds:

function(data) {
    var now = new Date().getTime();
    while (new Date().getTime() < now + 1000) {};
    console.log(count);

    // http request + more
}

The logs generated by this tells me that the callback is only executed when the app is back to foreground:

[home button pressed; app is suspended]

2016-06-14 16:00:24.934 App Development Edition[455:111798] didReceiveNotification with fetchCompletionHandler
2016-06-14 16:00:24.934 App Development Edition[455:111798] app in-active
2016-06-14 16:00:24.934 App Development Edition[455:111798] this should be a silent push
2016-06-14 16:00:24.934 App Development Edition[455:111798] Push Plugin notId 0000007422
2016-06-14 16:00:24.936 App Development Edition[455:111798] Notification received
2016-06-14 16:00:24.936 App Development Edition[455:111798] Push Plugin key: alert
2016-06-14 16:00:24.936 App Development Edition[455:111798] Push Plugin key: category
2016-06-14 16:00:24.937 App Development Edition[455:111798] Push Plugin key: badge
2016-06-14 16:00:24.937 App Development Edition[455:111798] Push Plugin key: sound
2016-06-14 16:00:24.937 App Development Edition[455:111798] Push Plugin key: content-available

[action button pressed]

2016-06-14 16:00:44.751 App Development Edition[455:111798] Push Plugin handleActionWithIdentifier App.push.approve
2016-06-14 16:00:44.752 App Development Edition[455:111798] Push Plugin userInfo {/*[...]*/}
2016-06-14 16:00:44.753 App Development Edition[455:111798] Push Plugin notId 0000007422
2016-06-14 16:00:44.756 App Development Edition[455:111798] Warning: Application delegate received call to -application:didReceiveRemoteNotification:fetchCompletionHandler: but the completion handler was never called.
2016-06-14 16:00:44.757 App Development Edition[455:111798] Notification received
2016-06-14 16:00:44.757 App Development Edition[455:111798] Push Plugin key: alert
2016-06-14 16:00:44.758 App Development Edition[455:111798] Push Plugin key: category
2016-06-14 16:00:44.758 App Development Edition[455:111798] Push Plugin key: badge
2016-06-14 16:00:44.758 App Development Edition[455:111798] Push Plugin key: sound
2016-06-14 16:00:44.770 App Development Edition[455:111798] Push Plugin key: content-available
2016-06-14 16:00:44.837 App Development Edition[455:111798] [App.push] notification: /* [...]*/

[long wait (~2 minutes); app reopened]

2016-06-14 16:01:06.554 App Development Edition[455:111798] active
2016-06-14 16:01:06.555 App Development Edition[455:111798] PushPlugin skip clear badge
2016-06-14 16:01:07.058 App Development Edition[455:111798] 0
2016-06-14 16:01:08.054 App Development Edition[455:111798] 1
2016-06-14 16:01:09.058 App Development Edition[455:111798] 2
2016-06-14 16:01:10.054 App Development Edition[455:111798] 3
2016-06-14 16:01:11.058 App Development Edition[455:111798] 4
2016-06-14 16:01:12.054 App Development Edition[455:111798] 5
2016-06-14 16:01:13.058 App Development Edition[455:111798] 6
2016-06-14 16:01:14.054 App Development Edition[455:111798] 7
2016-06-14 16:01:15.059 App Development Edition[455:111798] 8
2016-06-14 16:01:16.054 App Development Edition[455:111798] 9
2016-06-14 16:01:17.058 App Development Edition[455:111798] 10
2016-06-14 16:01:18.054 App Development Edition[455:111798] 11
2016-06-14 16:01:19.058 App Development Edition[455:111798] 12
2016-06-14 16:01:20.054 App Development Edition[455:111798] 13
2016-06-14 16:01:21.058 App Development Edition[455:111798] 14
2016-06-14 16:01:22.054 App Development Edition[455:111798] 15
2016-06-14 16:01:23.058 App Development Edition[455:111798] 16
2016-06-14 16:01:24.054 App Development Edition[455:111798] 17
2016-06-14 16:01:25.058 App Development Edition[455:111798] 18
2016-06-14 16:01:26.054 App Development Edition[455:111798] 19
2016-06-14 16:01:27.058 App Development Edition[455:111798] 20
2016-06-14 16:01:28.054 App Development Edition[455:111798] 21
2016-06-14 16:01:29.058 App Development Edition[455:111798] 22
2016-06-14 16:01:30.054 App Development Edition[455:111798] 23
2016-06-14 16:01:31.058 App Development Edition[455:111798] 24
2016-06-14 16:01:32.054 App Development Edition[455:111798] 25
2016-06-14 16:01:33.058 App Development Edition[455:111798] 26
2016-06-14 16:01:34.054 App Development Edition[455:111798] 27
2016-06-14 16:01:35.058 App Development Edition[455:111798] 28
2016-06-14 16:01:36.054 App Development Edition[455:111798] 29
2016-06-14 16:01:37.058 App Development Edition[455:111798] 30
2016-06-14 16:01:38.855 App Development Edition[455:111798] Push Plugin finish called
2016-06-14 16:01:38.865 App Development Edition[455:111798] [App.push] approve finished: {"0":null,"length":1}
2016-06-14 16:01:38.957 App Development Edition[455:111798] Push Plugin stopBackgroundTask called
2016-06-14 16:01:38.958 App Development Edition[455:111798] Push Plugin handlerObj
2016-06-14 16:01:38.959 App Development Edition[455:111798] Push Plugin: stopBackgroundTask (remaining t: 179769313486231570814527423731704356798070567525844996598917476803157260780028538760589558632766878171540458953514382464234321326889464182768467546703537516986049910576551282076245490090389328944075868508455133942304583236903222948165808559332123348274797826204144723168738177180919299881250404026184124858368.000000)

As you can see, the execution of the busy wait only happened after the app was brought back to foreground. So there's something wrong going on on this app. Or the docs (iOS docs included) aren't clear about what happens after the button is pressed.

@macdonst macdonst added retest and removed docs labels Jun 15, 2016
@macdonst
Copy link
Member

@panaggio hmmm...I will have to retest this. I remember being able to hit an HTTP endpoint from one of my action button listeners.

@panaggio
Copy link
Author

@macdonst is there anything I can do to help on that retest? Like creating a minimal app that reproduces the problem, or anything else. If there's anything I can do to help, let me know.

@macdonst
Copy link
Member

@panaggio sure that would help but I think I understand what is going on in your above example. What I really need now is some free time to do the testing.

@panaggio
Copy link
Author

panaggio commented Jul 4, 2016

I was trying to generate a sample app based on the phonegap-template-push, but for some reason I couldn't get the action button callback to be called. I just changed the www/js/index.js to look like this:

/*
 * Licensed to the Apache Software Foundation (ASF) under one
 * or more contributor license agreements.  See the NOTICE file
 * distributed with this work for additional information
 * regarding copyright ownership.  The ASF licenses this file
 * to you under the Apache License, Version 2.0 (the
 * "License"); you may not use this file except in compliance
 * with the License.  You may obtain a copy of the License at
 *
 * http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing,
 * software distributed under the License is distributed on an
 * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
 * KIND, either express or implied.  See the License for the
 * specific language governing permissions and limitations
 * under the License.
 */

var buildCallback = function(msg) {
    return function() {
        console.log('[push] ' + msg + ': ' + JSON.stringify(arguments));
    };
};

var app = {
    // Application Constructor
    initialize: function() {
        this.bindEvents();
    },
    // Bind Event Listeners
    //
    // Bind any events that are required on startup. Common events are:
    // 'load', 'deviceready', 'offline', and 'online'.
    bindEvents: function() {
        document.addEventListener('deviceready', this.onDeviceReady, false);
    },
    // deviceready Event Handler
    //
    // The scope of 'this' is the event. In order to call the 'receivedEvent'
    // function, we must explicitly call 'app.receivedEvent(...);'
    onDeviceReady: function() {
        console.log('Received Device Ready Event');
        console.log('calling setup push');
        app.setupPush();
    },

    setupPush: function() {
        console.log('calling push init');
        var push = PushNotification.init({
            ios: {
                categories: {
                    a: {
                        yes: {
                            title: 'Accept',
                            callback: 'accept',
                            foreground: true,
                        },
                    },
                },
                sound: true,
                vibration: true,
                badge: true,
            },
        });

        console.log('after init');

        push.on('registration', function(data) {
            console.log('registration event: ' + data.registrationId);

            var oldRegId = localStorage.getItem('registrationId');

            if (oldRegId !== data.registrationId) {
                // Save new registration ID
                localStorage.setItem('registrationId', data.registrationId);
                // Post registrationId to your app server as the value has
                // changed
            }

            var parentElement = document.getElementById('registration');
            var listeningElement = parentElement.querySelector('.waiting');
            var receivedElement = parentElement.querySelector('.received');

            listeningElement.setAttribute('style', 'display:none;');
            receivedElement.setAttribute('style', 'display:block;');
        });

        push.on('error', function(e) {
            console.log('push error = ' + e.message);
        });

        push.on('notification', function(data) {
            console.log('notification event');
            console.log('"' + data.title + '", "' + data.message + '"');
        });

        app.push = push;
    },

    accept: function(data) {
        console.log('accept');

        for(var count = 0; count <= 40; count++) {
            var now = new Date().getTime();

            while (new Date().getTime() < now + 1000) {
                _.noop();
            }

            console.log(count);
        }

        app.push.finish(
            buildCallback('approve finished'),
            buildCallback('approve error'),
            data.additionalData.notId
        );
    },
};

This is the closest I could get from transferring the code I have on my app right now to an isolated, easy to reproduce environment, but I couldn't get it to work properly. For some reason, the notification callback is called on action button click, but the proper callback (app.accept in this case) is never called. So my help here is more a request for extra help than current help :(

I can consistently reproduce this on the original app where the bug happened for the first time. And I removed a lot of code to look like the just pasted code, and I can still reproduce the bug. I think I'm missing something in this example app, but the error should be reproducible.

Sorry my help isn't really helpful :(

@macdonst
Copy link
Member

macdonst commented Jul 4, 2016

@panaggio Hey, I had a quick look at this a few weeks ago but was not able to reproduce it. I will sit down, hopefully sometime this week (I'm on vacation) to take a look.

In your above example your function is app.accept but in the categories setup you only have accept which is why I believe you are not getting the action button callback called.

@panaggio
Copy link
Author

panaggio commented Jul 4, 2016

@panaggio Hey, I had a quick look at this a few weeks ago but was not able to reproduce it. I will sit down, hopefully sometime this week (I'm on vacation) to take a look.

Sorry to interrupt your vacation. Enjoy it!

In your above example your function is app.accept but in the categories setup you only have accept which is why I believe you are not getting the action button callback called.

Sorry, that was broken on the example, but I've tried both ways. Actually, foreground was actually different from the behavior I wanted. The same problem happens when I use the following settings:

            ios: {
                categories: {
                    a: {
                        yes: {
                            title: 'Accept',
                            callback: 'app.accept',
                            foreground: false,
                        },
                    },
                },
                sound: true,
                vibration: true,
                badge: true,
            },

Which is a subset of what I use on the original app.

@jackvial
Copy link

jackvial commented Jul 6, 2016

I was having a similar issue with the action button callback not firing on iOS. After digging around and looking at the code I noticed that the property that is checked result.additionalData.actionCallback before executing the named callback was missing on iOS but there was a property called result.additionalData.callback . I'm not sure if this is a bug or if I am configuring the plugin incorrectly. I got it to work for me on iOS by adding an extra check for the result.additionalData.callback property.

Here is my modified version of the PushNotifiction function in push.js:

   var PushNotification = function(options) {
        console.log("PushNotification options: ", options);
        this._handlers = {
            'registration': [],
            'notification': [],
            'error': []
        };

        // require options parameter
        if (typeof options === 'undefined') {
            throw new Error('The options argument is required.');
        }

        // store the options to this object instance
        this.options = options;

        // triggered on registration and notification
        var that = this;
        var success = function(result) {
            var executeFunctionByName = function(functionName, context /*, args */ ) {

                // Ghetto logging since gapdebug console is not yet available if app is in background
                //localStorage.setItem('executeFunctionByName', functionName);
                var args = Array.prototype.slice.call(arguments, 2);
                var namespaces = functionName.split('.');
                var func = namespaces.pop();
                for (var i = 0; i < namespaces.length; i++) {
                    context = context[namespaces[i]];
                }
                return context[func].apply(context, args);
            };

            //localStorage.setItem('resultSuccess', JSON.stringify(result));
            if (result && typeof result.registrationId !== 'undefined') {
                that.emit('registration', result);
            } else if (result && result.additionalData && typeof result.additionalData.actionCallback !== 'undefined') {

                // Ghetto logging since gapdebug console is not yet available if app is in background
                //localStorage.setItem('actionCallback', result.additionalData.actionCallback);
                executeFunctionByName(result.additionalData.actionCallback, window, result);

            // Action callback is missing on iOS so check for additionalData.callback data too    
            } else if (result && result.additionalData && typeof result.additionalData.callback !== 'undefined') {

                // Ghetto logging since gapdebug console is not yet available if app is in background
                //localStorage.setItem('callback', result.additionalData.callback);
                executeFunctionByName(result.additionalData.callback, window, result);
            } else if (result) {
                that.emit('notification', result);
            }
        };

        // triggered on error
        var fail = function(msg) {
            var e = (typeof msg === 'string') ? new Error(msg) : msg;
            that.emit('error', e);
        };

        // wait at least one process tick to allow event subscriptions
        setTimeout(function() {
            exec(success, fail, 'PushNotification', 'init', [options]);
        }, 10);
    };

This is the data I was getting from the result object in the success callback on Android (I'ved changed the title and message text but all the fields are the same):

{
    "message": "AMAZING!",
    "additionalData": {
        "collapse_key": "do_not_collapse",
        "priority": "1",
        "coldstart": false,
        "data": {
            "message": "Some message",
            "actions": [{
                "callback": "track",
                "icon": "emailGuests",
                "title": "TRACK ORDER",
                "foreground": true
            }],
            "title": "AUX Scrum",
            "priority": 1
        },
        "actionCallback": "track",
        "payload": {
            "orderID": 9999999
        },
        "foreground": false,
        "actions": [{
            "callback": "track",
            "icon": "emailGuests",
            "foreground": true,
            "title": "TRACK ORDER"
        }]
    },
    "title": "Hi"
}

And iOS

{
    "additionalData": {
        "callback": "track",
        "foreground": false,
        "payload": {
            "orderID": 7777777
        },
        "message": "Also, AMAZING!!!",
        "category": "track",
        "coldstart": false,
        "notId": "1",
        "title": "Thing"
    },
    "message": "AMAZING!!!"
}

@macdonst
Copy link
Member

macdonst commented Jul 7, 2016

@jackvial your issue is different. I screwed up. I changed the identifier from callback to actionCallback but forgot to change it in the iOS code. I'll look at it tomorrow.

@macdonst
Copy link
Member

macdonst commented Jul 7, 2016

@jackvial I just pushed up a fix for your issue. Can you install the latest directly from https://github.com/phonegap/phonegap-plugin-push and give it a try? I'm pretty sure it'll work for you without the extra:

} else if (result && result.additionalData && typeof result.additionalData.callback !== 'undefined') {

Basically, iOS 10 adds it's own callback parameter (#1002) so I needed to change the one we use to actionCallback and the changes got in for Android but I missed checking in the iOS changes, which are minimal.

@jackvial
Copy link

jackvial commented Jul 7, 2016

@macdonst Thanks for the quick fix. I installed the the plugin directly from github to get the HEAD of master branch and I can confirm that it is working as intended on both iOS and Android 😄

@macdonst
Copy link
Member

macdonst commented Jul 7, 2016

@jackvial yeah, it was trivial change as I am a dork. I changed it in a project I was using to test but forgot to add it into my checkin for that issue. I will publish I new version today, just looking at a way to streamline my publishing after seeing this https://github.com/sindresorhus/np

@jackvial
Copy link

jackvial commented Jul 8, 2016

@macdonst Simple when you know how! Objective C syntax still looks strange to me with all it's weird brackets and what not! 😛 np looks really handy, will book mark it for future use.

@macdonst
Copy link
Member

macdonst commented Jul 8, 2016

@jackvial I'm actually writing my own version of np that will update plugin.xml, package.json and setup the git tag for me right now.

@panaggio
Copy link
Author

After a lot of problem trying to reproduce consistently with little to no code since 1.6.(I don't remember), I just reproduced the bug with a similar code to the aforementioned one, using the latest version of this plugin (it was impossible to reproduce with 1.7.2; I'm not sure if it was tested with 1.7.3 or any other than 1.7.2, because I didn't keep track of the version numbers back than). The problem isn't on that code (although I've made a lot of changes so that I could reproduce the bug I was experiencing), but on a necessary condition for the bug to happen: the presence of the plugin wkwebview-engine-localhost, which is (was? I'm not sure) experimental.

Now I need some time to be sure that the problem isn't in wkwebview-engine-localhost itself or in the co-occurrence of both plugins. As soon as I have any news, I'll post here. Now that it's easily reproducible I can finally start to narrow down the problem.

Sorry for bothering before without this information before, but even disabling a plugin at a time back than wasn't helping me to isolate the problem. I continued to happen. I'm not sure where my testings were wrong or even if they were wrong at all, but I'm glad this was finally narrowed down. Now we'll be able to make progress! o/

@macdonst
Copy link
Member

@panaggio no problem. Glad you got it narrowed down. I'm going to close this for now but re-open when you have some more findings.

@srgpqt
Copy link

srgpqt commented Mar 7, 2017

I'm also experiencing this issue. Sometimes the callback runs, sometimes it does not. Exact same push notification payloads. Very frustrating... (on v1.8.4 of the plugin. I'll try upgrading to 1.9 and test again)

@srgpqt
Copy link

srgpqt commented Mar 7, 2017

Same issue with 1.9.4

@srgpqt
Copy link

srgpqt commented Mar 7, 2017

I believe I found the issue.
The finish() function must be called in the action callback, not just in the notification callback..

@lock
Copy link

lock bot commented Jun 4, 2018

This thread has been automatically locked.

@lock lock bot locked as resolved and limited conversation to collaborators Jun 4, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Development

No branches or pull requests

4 participants