Parse.FacebookUtils.unlink timeout

[mtrezza]

Issue Description

When trying to unlink a user in cloud code the Parse.FacebookUtils.unlink times out.

function unlinkUserWithId(userId) {

    return new Promise(function(resolve, reject) {

        // Get user
        var user = new Parse.Object(Globals.Identifiers.UserClass);
        user.id = userId;
        user.fetch({useMasterKey: true})
        .then(
            function(user) {
                return Parse.FacebookUtils.unlink(user, {useMasterKey: true});
            }
        )
        .then(
            function() {
                resolve();
            },
            function(error) {
                reject(error);
            }
        );
    });
}

Steps to reproduce

1. Sign up user with Facebook
2. Call function to unlink user in cloud code

Expected Results

Function should return a promise resolved or rejected.

Actual Outcome

Function times out.

Environment Setup

• Server

  • parse-server version: 2.4.2

• Database

  • MongoDB version: 3.2.11

[flovilmart]

Can you provide the server logs when running with VERBOSE=1?

[mtrezza]

@flovilmart, sure:

2017-06-15T13:12:40.673675+00:00 heroku[router]: at=error code=H12 desc="Request timeout" method=POST path="/parse/functions/deactivateAccount" host=DDDDDDDDD request_id=QQQQQQQQQ fwd="XXX.XXX.XXX.XXX" dyno=web.1 connect=0ms service=30001ms status=503 bytes=0 protocol=https
2017-06-15T13:13:00.815100+00:00 heroku[router]: at=info method=POST path="/parse/classes/_User/XXXXXXXXXX" host=DDDDDDDDD request_id=541e474e-ca63-4c4e-a58a-ae5e849905a0 fwd="XXX.XXX.XXX.XXXX" dyno=web.1 connect=0ms service=85ms status=200 bytes=522 protocol=https
2017-06-15T13:13:00.650691+00:00 app[web.1]: [36mverbose[39m: REQUEST for [POST] /parse/functions/deactivateAccount: {} method=POST, url=/parse/functions/deactivateAccount, host=DDDDDDDDD, connection=close, accept=*/*, x-parse-session-token=TTTTTTTTT, x-parse-application-id=WWWWWWWWWWWWWWW, x-parse-client-key=ZZZZZZZZZZZZZZZZZZZZZZZZZZZ, x-parse-installation-id=YYYYYYYYYYYYYYYYY, accept-encoding=gzip, deflate, x-parse-os-version=10.3.1 (16F73), accept-language=en-us, x-parse-client-version=i1.14.2, user-agent=AAAAAAA/102 CFNetwork/811.4.18 Darwin/16.6.0, x-parse-app-build-version=102, x-parse-app-display-version=1.11, x-request-id=EEEEEEEEEEEEEEE, x-forwarded-for=XXX.XXX.XXX.XXX, x-forwarded-proto=https, x-forwarded-port=443, via=1.1 vegur, connect-time=0, x-request-start=1497532380613, total-route-time=0, content-length=0, 
2017-06-15T13:13:00.651495+00:00 app[web.1]: deactivateUserAccount: deactivating user account: XXXXXXXXXX
2017-06-15T13:13:00.691353+00:00 app[web.1]: [36mverbose[39m: REQUEST for [GET] /parse/classes/_User/XXXXXXXXXX: {} method=GET, url=/parse/classes/_User/XXXXXXXXXX, host=DDDDDDDDD, connection=close, user-agent=node-XMLHttpRequest, Parse/js1.9.2 (NodeJS 8.1.2), accept=*/*, content-type=text/plain, x-request-id=RRRRRRRRRR, x-forwarded-for=XXX.XXX.XXX.XXXX, x-forwarded-proto=https, x-forwarded-port=443, via=1.1 vegur, connect-time=1, x-request-start=1497532380682, total-route-time=0, content-length=217, 
2017-06-15T13:13:00.708036+00:00 app[web.1]: [36mverbose[39m: RESPONSE from [GET] /parse/classes/_User/XXXXXXXXXX: {
2017-06-15T13:13:00.708039+00:00 app[web.1]:   "response": {
2017-06-15T13:13:00.708041+00:00 app[web.1]:     "objectId": "XXXXXXXXXX",
2017-06-15T13:13:00.708042+00:00 app[web.1]:     "username": "bohzjzpgpg_149@tfbnw.net",
2017-06-15T13:13:00.708043+00:00 app[web.1]:     "createdAt": "2017-06-15T10:43:20.919Z",
2017-06-15T13:13:00.708043+00:00 app[web.1]:     "updatedAt": "2017-06-15T13:12:10.808Z",
2017-06-15T13:13:00.708044+00:00 app[web.1]:     "email": "bohzjzpgpg_149@tfbnw.net",
2017-06-15T13:13:00.708045+00:00 app[web.1]:     "deletedAt": {
2017-06-15T13:13:00.708045+00:00 app[web.1]:       "__type": "Date",
2017-06-15T13:13:00.708046+00:00 app[web.1]:       "iso": "2017-06-15T13:12:10.769Z"
2017-06-15T13:13:00.708047+00:00 app[web.1]:     },
2017-06-15T13:13:00.708047+00:00 app[web.1]:     "ACL": {
2017-06-15T13:13:00.708048+00:00 app[web.1]:       "XXXXXXXXXX": {
2017-06-15T13:13:00.708048+00:00 app[web.1]:         "read": true,
2017-06-15T13:13:00.708049+00:00 app[web.1]:         "write": true
2017-06-15T13:13:00.708049+00:00 app[web.1]:       }
2017-06-15T13:13:00.708050+00:00 app[web.1]:     }
2017-06-15T13:13:00.708050+00:00 app[web.1]:   }
2017-06-15T13:13:00.708052+00:00 app[web.1]: } objectId=XXXXXXXXXX, username=bohzjzpgpg_149@tfbnw.net, createdAt=2017-06-15T10:43:20.919Z, updatedAt=2017-06-15T13:12:10.808Z, email=bohzjzpgpg_149@tfbnw.net, __type=Date, iso=2017-06-15T13:12:10.769Z, read=true, write=true
2017-06-15T13:13:00.714668+00:00 app[web.1]: deactivateUserAccount: deactivating username and email of user XXXXXXXXXX
2017-06-15T13:13:00.740454+00:00 app[web.1]: [[39m: REQUEST for [PUT] /parse/classes/_User/XXXXXXXXXX: {
2017-06-15T13:13:00.740456+00:00 app[web.1]:   "deletedAt": {
2017-06-15T13:13:00.740457+00:00 app[web.1]:     "__type": "Date",
2017-06-15T13:13:00.740458+00:00 app[web.1]:     "iso": "2017-06-15T13:13:00.715Z"
2017-06-15T13:13:00.740459+00:00 app[web.1]:   },
2017-06-15T13:13:00.740460+00:00 app[web.1]:   "username": "bohzjzpgpg_149@tfbnw.net",
2017-06-15T13:13:00.740461+00:00 app[web.1]:   "email": "bohzjzpgpg_149@tfbnw.net"
2017-06-15T13:13:00.740463+00:00 app[web.1]: } method=PUT, url=/parse/classes/_User/XXXXXXXXXX, host=DDDDDDDDD, connection=close, user-agent=node-XMLHttpRequest, Parse/js1.9.2 (NodeJS 8.1.2), accept=*/*, content-type=text/plain, x-request-id=541e474e-ca63-4c4e-a58a-ae5e849905a0, x-forwarded-for=XXX.XXX.XXX.XXXX, x-forwarded-proto=https, x-forwarded-port=443, via=1.1 vegur, connect-time=0, x-request-start=1497532380728, total-route-time=0, content-length=589, __type=Date, iso=2017-06-15T13:13:00.715Z, username=bohzjzpgpg_149@tfbnw.net_10b216ff-ed53-4030-b06e-2a2b3eb0d004, email=bohzjzpgpg_149@tfbnw.net_10b216ff-ed53-4030-b06e-2a2b3eb0d004
2017-06-15T13:13:00.811830+00:00 app[web.1]: [36mverbose[39m: RESPONSE from [PUT] /parse/classes/_User/XXXXXXXXXX: {
2017-06-15T13:13:00.811835+00:00 app[web.1]:   "response": {
2017-06-15T13:13:00.811836+00:00 app[web.1]:     "updatedAt": "2017-06-15T13:13:00.740Z"
2017-06-15T13:13:00.811837+00:00 app[web.1]:   }
2017-06-15T13:13:00.811837+00:00 app[web.1]: } updatedAt=2017-06-15T13:13:00.740Z
2017-06-15T13:13:00.818714+00:00 app[web.1]: deactivateUserAccount: unlinking authData of user XXXXXXXXXX
2017-06-15T13:13:00.709904+00:00 heroku[router]: at=info method=POST path="/parse/classes/_User/XXXXXXXXXX" host=DDDDDDDDD request_id=RRRRRRRRRR fwd="XXX.XXX.XXX.XXXX" dyno=web.1 connect=1ms service=25ms status=200 bytes=975 protocol=https
2017-06-15T13:13:30.615610+00:00 heroku[router]: at=error code=H12 desc="Request timeout" method=POST path="/parse/functions/deactivateAccount" host=DDDDDDDDD request_id=EEEEEEEEEEEEEEE fwd="XXX.XXX.XXX.XXX" dyno=web.1 connect=0ms service=30001ms status=503 

[mtrezza]

@flovilmart, btw, the unlinking is successful as the authData field is empty after `Parse.FacebookUtils.unlink' call. But the call times out.

I changed the code to:

Parse.FacebookUtils.unlink(_user, null, {
                    success: function(user) {
                        console.log("deactivateAccount: unlinking authData success");
                        return Parse.Promise.as(user);
                    }, 
                    error: function(user, error) {
                        console.log("deactivateAccount: unlinking authData error: " + error);
                        return Parse.Promise.as(user);
                    }
                });

Also here the unlinking is successfull but neither console.log line is reached.

[flovilmart]

i don't see any logs for the unlink calls in the logs (should have {authData: null} in the payload).

[mtrezza]

@flovilmart Do you have any idea what I could do to investigate further? The unlink happens and authData becomes null, but it always times out.

[flovilmart]

I don't see the call to the unlink in the logs which is very odd. and we have coverage for that feature, so could you try:

return new Promise((resolve, reject) => {
  Parse.FacebookUtils.unlink(_user, {
    useMasterKey: true,
    success: function(user) {
      console.log("deactivateAccount: unlinking authData success");
      return resolve(user);
    }, 
    error: function(user, error) {
        console.log("deactivateAccount: unlinking authData error: " + error);
        reject(error);
    }
  });
});

[mtrezza]

@flovilmart, same result in the log.

Here is the whole cloud code function structure if it helps:

function deactivateUserAccount(userId) {

    return new Promise(function(resolve, reject) {

        /// The user
        var _user = null;

        // Get user
        var user = new Parse.Object("_User");
        user.id = userId;
        user.fetch({useMasterKey: true})
        .then(
            function(user) {
                _user = user;

                // ... changing the username and email fields
                return user.save(null, {useMasterKey: true});
            })
        .then(
            function(user) {
                console.log("unlinking authData...");

                return new Promise((resolve, reject) => {
                  Parse.FacebookUtils.unlink(_user, {
                    useMasterKey: true,
                    success: function(user) {
                      console.log("unlinking authData success");
                      return resolve(user);
                    }, 
                    error: function(user, error) {
                        console.log("unlinking authData error: " + error);
                        reject(error);
                    }
                  });
                });
            })
        .then(
            function(user) {
                //...
            })
        .then(
            function() {
                resolve("");
            },
            function(error) {
                reject(error);
            }
        );
    });
}

[flovilmart]

you're passing _ user and it seems tu be null (never set as per your code)

[mtrezza]

I cut it out in the comment accidentally, updated the comment now.

[flovilmart]

Ok, what's odd is that the unlink call never reaches the server, the investigation should start inside the JS SDK, adding logs/breakpoints alongside the unlink code path.

[mtrezza]

I think the unlink call does reach the server, because the authData field is cleared. But neither of the callback functions of Parse.FacebookUtils.unlink is called.

[flovilmart]

That would be interesting to know for sure why this call never reaches the server. And why it's never fired, without that I can't say where the error comes from.

[flovilmart]

The call is not logged, we should see a PUT call on the server logs coming in.

[acinader]

add a

.catch(reject)

to the end of your promise chain.

and, are you sure that you are returning a promise in the first .then() below?

        .then(
            function(user) {
                //...
            })
        .then(
            function() {
                resolve("");
            },
            function(error) {
                reject(error);
            }
        );

[mtrezza]

So I created a cloud job to test unlinking and found that I did not call Parse.FacebookUtils.init.
After adding it, the cloud job looks like this:

Parse.Cloud.job("unlinkTest", function(request, response) {

    // Get user id
    var userId = request.headers["x-parse-user-id"];

    // If no user ID is given
    if (userId === undefined) {

        response.error("error in unlinkFacebookForUserId: no user ID set");
        return;
    }

    // Get user
    var userQuery = new Parse.Query(Globals.Identifiers.UserClass);
    userQuery.equalTo(Globals.Identifiers.UserFieldObjectId, userId);
    userQuery.first({useMasterKey: true})
    .then(
        function(user) {

            // If user not found
            if (user === undefined) {
                throw new Error("user not found with ID: " + userId);
                return;
            }

            // Init facebook SDK
            Parse.FacebookUtils.init({
                appId: XXXXXXXX,
                autoLogAppEvents: true,
                status: true,
                cookie: true,
                xfbml: true,
                version: "v2.9"
            });

            // Unlink auth data
            return Parse.FacebookUtils.unlink(user, {useMasterKey: true});
        }
    )
    .then(
        function(user) {
            console.log("unlinkTest: unlinked facebook for user " + user.id);
            response.success("unlinkTest: unlinked facebook for user " + user.id);
        },
        function(error) {
            console.log("error in unlinkTest: " + error);
            response.error("error in unlinkTest: " + error);
        }
    );
});

And fails with:
error in unlinkTest: Error: The Facebook JavaScript SDK must be loaded before calling init.

How do I load the SDK?