How to properly debug the response lifecyle in Sails.js?

Question

Using sails.js I got these controller methods which perform db requests and use promises. The problem is that they're working but when a request is performed a 504 is obtained at client side.

I want to make sure my implementation is good and the 504 is not a problem in sails/node coding but any nginx or something else. I set log mode to silly in config/logs.js but I can't even see everytime response.send is invoked.

Both methods bellow present such issue but (maybe coincidence) with first method is only happening sometimes.

Method 1

addPlayer: function (request,response) {

console.log("Add player");
var lineupId = request.params.id;

var receivedPlayer = request.param('player');
var playerId = receivedPlayer.id;
var bench = receivedPlayer.bench;
var place = receivedPlayer.place;

LineUp.findOne().where({id: lineupId}).then(function (foundLineUp) {

  var player = Player.findOne().where({id: playerId}).then(function (player) {
    console.log("Found player with _id " + player.id);
    return player;
  });

  return [foundLineUp,player];

  }).spread(function (lineup,player) {

    if (!lineup)
      return response.send(404);

    if (!player)
      return response.send(409, "El jugador " + playerId + " no existe");

    else if (!lineup.formation)
      return response.send(409, "No se ha elegido una táctica para esta alineación");

    if (lineup.squadIsComplete())
      return response.send(409, "La plantilla ya contiene el máximo de 15 jugadores");

    if (lineup.playerWasAdded(player.id))
      return response.send(409, "El jugador ya ha sido agregado a la alineación");

    if (lineup.fieldIsComplete() && !bench)
      response.send(409, "Ya se han agregado los 11 jugadores de campo");

    /*If there's already a player with same position, return 409, should modify*/

    player.bench = bench;
    player.place = place;

    lineup.players.push(player);

    /*
        MISSING: Add field or bench player and rearrange squad
    */

    // If any of rule restrictions evaluates to true ...
    // Using lodash _.some with out second argument which defaults to _.identity
    if ( _.some([ lineup.reachesMaxForeignPlayers(),
                  lineup.reachesBudgetLimit(),
                  lineup.reachesMaxSameTeamLimit(),
                  lineup.reachesMaxSameFavoriteTeamLimit()]) ) {

      response.send(400, "La inclusión de este jugador no satisface las reglas del juego");
    }

    // Whole rule validations passed through
    else {
      lineup.save().then(function (saved) {

        // Pluck missing, valid while DEV
        return response.send(202,JSON.stringify(saved));
      });
    }
  }).
  catch(function (err) {

    console.log(err);
    response.send(500,JSON.stringify(err));
  })

}

Method 2

deletePlayer: function (request,response) {

  console.log("deletePlayer");

  var lineupId = request.param('id');
  var playerId = request.param('player');

  LineUp.findOne().where({id: lineupId}).then(function (foundLineUp) {
    _.remove(foundLineUp.players, function(player) {
      console.log(player.id + " || " + playerId);
      return player.id === playerId;
    });

    console.log("Ended remove");

    foundLineUp.save().then(function (savedLineup) {

      console.log("Saved lineup\n\n:" + JSON.stringify(savedLineup));
      return response.send(202, JSON.stringify(savedLineup));
    }).catch(function (err) {

      console.log("save lineup err");
      response.send(500, JSON.stringify(err));
    });
  }).catch(function (err) {
    console.log(err);
    return response.send(500, JSON.stringify(err));
  });
}

Answer 1

I think it is a timeout because you're not returning what you resolved in the promise:

addPlayer: function(request, response) {

    console.log("Add player");
    var lineupId = request.params.id;

    var receivedPlayer = request.param('player');
    var playerId = receivedPlayer.id;
    var bench = receivedPlayer.bench;
    var place = receivedPlayer.place;

    return LineUp.findOne().where({
        id: lineupId
    }).then(function(foundLineUp) {
        
        return Player.findOne().where({
            id: playerId
        }).then(function(player) {
            console.log("Found player with _id " + player.id);
            return [foundLineUp, player];
        });

    }).spread(function(lineup, player) {

        if (!lineup)
            return response.send(404);

        if (!player)
            return response.send(409, "El jugador " + playerId + " no existe");

        else if (!lineup.formation)
            return response.send(409, "No se ha elegido una táctica para esta alineación");

        if (lineup.squadIsComplete())
            return response.send(409, "La plantilla ya contiene el máximo de 15 jugadores");

        if (lineup.playerWasAdded(player.id))
            return response.send(409, "El jugador ya ha sido agregado a la alineación");

        if (lineup.fieldIsComplete() && !bench)
            response.send(409, "Ya se han agregado los 11 jugadores de campo");

        /*If there's already a player with same position, return 409, should modify*/

        player.bench = bench;
        player.place = place;

        lineup.players.push(player);

        /*
            MISSING: Add field or bench player and rearrange squad
        */

        // If any of rule restrictions evaluates to true ...
        // Using lodash _.some with out second argument which defaults to _.identity
        if (_.some([lineup.reachesMaxForeignPlayers(),
                lineup.reachesBudgetLimit(),
                lineup.reachesMaxSameTeamLimit(),
                lineup.reachesMaxSameFavoriteTeamLimit()
            ])) {

            response.send(400, "La inclusión de este jugador no satisface las reglas del juego");
        }

        // Whole rule validations passed through
        else {
            lineup.save().then(function(saved) {

                // Pluck missing, valid while DEV
                return response.send(202, JSON.stringify(saved));
            });
        }
    }).
    catch(function(err) {

        console.log(err);
        response.send(500, JSON.stringify(err));
    })

}

Answer 2

In method 1 you have:

LineUp.findOne().where({id: lineupId}).then(function (foundLineUp) {

      var player = Player.findOne().where({id: playerId}).then(function (player) {
        console.log("Found player with _id " + player.id);
        return player;
      });

      return [foundLineUp,player];

      }).spread(function (lineup,player){...

when you call 'then' in:

var player = Player.findOne().where({id: playerId}).then(...)

you are returning 'player', but it is returned in the callback body.

That doesn't imply that this will be executed before the line:

return [foundLineUp,player];

that is the input of 'spread'.

This should work:

LineUp.findOne().where({
        id: lineupId
    }).then(function(foundLineUp) {

        return Player.findOne().where({
            id: playerId
        }).then(function(player) {
            console.log("Found player with _id " + player.id);
            return [foundLineUp, player];
        });

    }).spread(function(lineup, player) {....

Here you are waiting for the promise to be resolved and player and lineup values are returned in an array, so spread can continue.