parse-community / parse-server

Parse Server for Node.js / Express
https://parseplatform.org
Apache License 2.0
20.83k stars 4.77k forks source link

Issue with sending pushes from Parse Server #1245

Closed leonluc-dev closed 8 years ago

leonluc-dev commented 8 years ago

Node.JS 4.4 Python 2.7.11 Parse Server 2.2.2 Self hosted MongoDB 3.0.10-1.5 (Storage engine: Rocksdb) Debian 8

Description of issue

Currently we having an issue with push notifications sent from Parse Server cloud code. Sending out push notifications does not work and the Parse.com dashboard starts showing issues when _PushStatus entries created by parse-server are present in the database.

While migrating to our own Parse Server we are still sending Push notifications from our hosted Parse.com Cloud Code environment. This still works fine even with a self-hosted MongoDB instance.

The first issue encountered in Parse Server is that push notifications aren't being sent out properly. The status of the push is stuck on Running with 0 pushes being sent out (on an audience of about 800-1000 pushes).

The second issue is that once a _PushStatus entry is created by Parse Server, the Parse.com hosted dashboard doesn't list any push entries on the push tab anymore. It just shows a message "No pushes to display yet. You may need to configure push notifications for your app." until all _PushStatus entries created by Parse Server are removed from the database (or end up on the second page of the push list, therefore allowing the first page to load properly again).

The Parse.com hosted code and our Parse Server code calling Parse.Push.send() is identical. Both environment use the same connection string to query and manipulate the self hosted MongoDB instance. Both environments also use the same apn push certificates/gcm sender ids

Logs/trace

Here is an example of a _PushStatus entry sent from Parse.com hosted cloud code that succeeded:

{
    "_id" : "BfDvKA6DJQ",
    "_created_at" : ISODate("2016-03-29T07:24:59.780Z"),
    "_updated_at" : ISODate("2016-03-29T07:25:01.785Z"),
    "source" : "cloud_code",
    "query" : "{\"channels\":{\"$in\":[\"News\",\"all\"]}}",
    "payload" : "{\"alert\":\"OMITTED \",\"badge\":\"Increment\",\"title\":\"OMITTED\",\"uri\":\"OMITTED\"}",
    "status" : "succeeded",
    "numSent" : 866,
    "pushHash" : "05e34d28cccd81d0d42456a4224863e7",
    "expansionDuration" : 0.677969696,
    "sentPerType" : {
        "embedded" : 0,
        "winphone" : 0,
        "js" : 0,
        "winrt" : 1,
        "android" : 522,
        "ios" : 343,
        "osx" : 0
    }
}

And here is a _PushStatus entry sent from Parse Server Cloud Code that failed (stuck on "running" status).

{
    "_id" : ObjectId("56fa2e992121357c31f1e72f"),
    "objectId" : "8Rnbtvti14",
    "pushTime" : "2016-03-29T07:28:25.966Z",
    "_created_at" : ISODate("2016-03-29T07:28:25.966Z"),
    "query" : "{\"channels\":{\"$in\":\"news\",\"all\"]}}",
    "payload" : {
        "alert" : "*OMITTED*",
        "badge" : "Increment",
        "title" : "*OMITTED*",
        "uri" : "*OMITTED*"
    },
    "source" : "rest",
    "title" : null,
    "expiry" : null,
    "status" : "running",
    "numSent" : 0,
    "pushHash" : "14f5359b3cc94f0f463fd5403a52a5da",
    "_wperm" : [],
    "_rperm" : []
}
flovilmart commented 8 years ago

Try running with VERBOSE=1 DEBUG=apn,node-gcm environment variables set. That will add more logs on apn and gcm an maybe point us to the right direction

gfosco commented 8 years ago

How was the push sent? From the _id value, it appears this push status object was not created by parse-server, as it would use the newObjectId method in cryptoUtils.js and not have a mongo object id... and the invalid id is a probable cause for the dashboard failures.

leonluc-dev commented 8 years ago

Try running with VERBOSE=1 DEBUG=apn,node-gcm environment variables set. That will add more logs on apn and gcm an maybe point us to the right direction

Here is the log that this generates when sending a Push (omitted some info):

[[Tue 29 Mar 2016 12:07:02]] [LOG]   POST /parse/push { 'user-agent': 'node-XMLHttpRequest, Parse/js1.8.1 (NodeJS 4.4.0)',
  accept: '*/*',
  'content-type': 'text/plain',
  host: 'OMITTED:17890',
  'content-length': '497',
  connection: 'close' } {
  "channels": [
    "news",
    "all"
  ],
  "data": {
    "alert": "OMITTED",
    "badge": "Increment",
    "title": "OMITTED",
    "uri": "OMITTED"
  }
}
[[Tue 29 Mar 2016 12:07:02]] [LOG]   response: {
  "response": {
    "result": true
  }

How was the push sent? From the _id value, it appears this push status object was not created by parse-server, as it would use the newObjectId method in cryptoUtils.js and not have a mongo object id... and the invalid id is a probable cause for the dashboard failures.

It was sent using the Parse.Push.send() function in Cloud Code. It's strange too. This seems to be the only method that does this. All the other database manipulations from Parse Server (including manipulations for the _Installation, _User collections etc.) don't do this and use the Parse Server generated id and set it to the _id column

leonluc-dev commented 8 years ago

Update:

I figured out this line causes a error leading to the code not to continue:

Line 102, PushController.js

var badgeInstallationsMap = installations.reduce(function (map, installation) {
            var badge = installation.badge;
            if (installation.deviceType != "ios") {
              badge = UNSUPPORTED_BADGE_KEY;
            }
            map[badge + ''] = map[badge + ''] || [];
            map[badge + ''].push(installation);
            return map;
          }, {});

For some reason in this line of code the reduce call fails because the installations object is undefined according to the log. (can't call reduce on an undefined object.) even though the installations object seems to be defined because if I comment out this block (line 100-123) the rest of the push notification process using the installations object works fine.

flovilmart commented 8 years ago

so when you console.log(installations) it says undefined?

can you check https://github.com/ParsePlatform/parse-server/blob/master/src/Controllers/PushController.js#L93 if response is properly set?

leonluc-dev commented 8 years ago

I have added a few lines of logging and error catching like this:

.then(function (response) {
        pushStatus.setRunning();
        console.log("Result count: "+response.results.length); //A full output was too big of a log result ;-)
        return this.sendToAdapter(body, response.results, pushStatus, config);
      }).then(function (results) {
        return pushStatus.complete(results);
      });
   try{
       console.log("Result count in sendToAdapter: "+installations.length);
       let badgeInstallationsMap = installations.reduce(function (map, installation) {
            var badge = installation.badge;
            if (installation.deviceType != "ios") {
              badge = UNSUPPORTED_BADGE_KEY;
            }
            map[badge + ''] = map[badge + ''] || [];
            map[badge + ''].push(installation);
            return map;
          }, {});

          // Map the on the badges count and return the send result
          var promises = Object.keys(badgeInstallationsMap).map(function (badge) {
            let payload = deepcopy(body);
            if (badge == UNSUPPORTED_BADGE_KEY) {
              delete payload.data.badge;
            } else {
              payload.data.badge = parseInt(badge);
            }
            return this.adapter.send(payload, badgeInstallationsMap[badge]);
          });
   }
   catch(error)
   {
         console.error("Error occured: "+error);
    }

This results in the following log:


[[Tue 29 Mar 2016 18:58:02]] [LOG]   Result count: 1387
[[Tue 29 Mar 2016 18:58:02]] [LOG]   Result count in sendToAdapter: 1387
[[Tue 29 Mar 2016 18:58:02]] [ERROR] Error occured: TypeError: Cannot read property 'reduce' of undefined
flovilmart commented 8 years ago

Any idea what's going on? What's the error stack? maybe it's badgeInstallationsMap[badge] that is undefined and the library below doing the reduce

leonluc-dev commented 8 years ago

After some more debugging I managed to narrow it down to the following code block in the GCM.js file:

GCM.js, Line 50-68

devices = slices[0];

  let expirationTime;
  // We handle the expiration_time convertion in push.js, so expiration_time is a valid date
  // in Unix epoch time in milliseconds here
  if (data['expiration_time']) {
    expirationTime = data['expiration_time'];
  }
  // Generate gcm payload
  // PushId is not a formal field of GCM, but Parse Android SDK uses this field to deduplicate push notifications
  let gcmPayload = generateGCMPayload(data.data, pushId, timestamp, expirationTime);
  // Make and send gcm request
  let message = new gcm.Message(gcmPayload);

  // Build a device map
  let devicesMap = devices.reduce((memo, device) => {
    memo[device.deviceToken] = device;
    return memo;
  }, {});

I also figured out the reason why devices is undefined here. In case of push sets where there are only iOS based installations (which is the case when dealing with installations with a badge value set) the installations set send to the GCM.send() function by the PushController is empty. This naturally leads to the resulting slices set being empty as well.

This will make it so the devices = slices[0]; statement will set the devices variable to undefined and as a result the var devicesMap = devices.reduce() statement a few lines later will fail with the error mentioned earlier.

It seems the way to solve this is to either do a undefined/empty check on the devices parameter in GCM.send() or to change the ParsePushAdapter code block to not call a sender if there are 0 devices for that pushType present in the deviceMap.

I have added a pull request using the latter solution to the parse-server-push-adapter over here

flovilmart commented 8 years ago

Nice tracking down! Thanks for the debugging. We'll close that one when we merge