Function being called twice at the same time

731 views
Skip to first unread message

Eliezer Steinbock

unread,
Aug 14, 2014, 2:44:14 AM8/14/14
to meteo...@googlegroups.com
Hi,

I have a piece of code that works 99 percent of the time, but occasionally fails and I'm trying to work out why.

It's a fantasy football game and in the draft users go in turns to pick players.

When you pick a player, two docs get updated: your team in the Teams collection and your league in the Leagues collection.
Your team gets updated with the player you picked and the league is updated to say that it's the next player's turn.
Before you pick a player, there's a check to see if it's currently your turn to pick.

The site is live and it's been working fine in general, but occasionally I run into the problem that this function is called twice and a player picks twice in a row.

One thing to note is that a timeout is set to pick for a player automatically if he hasn't picked within the allotted time. So I think the problem arises when you pick exactly when your time limit runs out and then two calls to the "pick player" function are made and each pick goes through because they each pass my check as to whose turn it is.

My question is how is this possible in Node.js? I thought everything runs in a single thread so the function couldn't be running twice at the same time.

Or is it something to do with mongodb and the database not being updated quickly enough? I'm using a MongoHQ elastic deployment.

I hope the question is clear. Any thoughts on how to fix the problem would be appreciated. I think I'll have to create a variable that keeps track of whose pick it is currently. At the moment this information is only stored in the Leagues collection.

If you want to check out the site, it's called DraftFantasyFootball.co.uk.

mk_too

unread,
Aug 14, 2014, 4:16:24 AM8/14/14
to meteo...@googlegroups.com
Hi Eliezer,

Check the docs on this.unblock() inside a method call.  It says: "On the server, methods from a given client run one at a time. ".  Collections.update() from client is a method call. 

So what you intend is definitely possible.  Maybe show the code where you update whose turn it is and check the turn before allowing a player pick? 

Eliezer Steinbock

unread,
Aug 14, 2014, 4:44:26 AM8/14/14
to meteo...@googlegroups.com

The thing is, the setTimeout for the automatic pick is from the server. The user picks using a meteor method.

I'll try post some code tonight. I really want to get this bug sorted quickly.

--
You received this message because you are subscribed to a topic in the Google Groups "meteor-talk" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/meteor-talk/j1YF7JO5Rdo/unsubscribe.
To unsubscribe from this group and all its topics, send an email to meteor-talk...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Andrew Mao

unread,
Aug 14, 2014, 11:55:14 PM8/14/14
to meteo...@googlegroups.com
I think I just reported the same bug: https://github.com/meteor/meteor/issues/2407

It seems that method calls are not idempotent in Meteor and that retries can actually get executed twice in rare cases.

Andrew Mao

unread,
Aug 14, 2014, 11:56:13 PM8/14/14
to meteo...@googlegroups.com
one band-aid, from the errors I showed in that issue, is to pick a Random.id() on the client for each operation and reject an operation if that id already exists in the database (easy with unique key constraint).

Eliezer Steinbock

unread,
Aug 15, 2014, 3:55:31 AM8/15/14
to meteo...@googlegroups.com
Nice. Good to know I'm not the only one with this issue.

Eliezer Steinbock

unread,
Aug 15, 2014, 6:25:51 AM8/15/14
to meteo...@googlegroups.com
In fact, thinking about the symptoms of my problem a bit more, I don't think I'm having the same problem as you.

My problem isn't the same meteor method being called twice. I can tell by the parameters that are being sent. It's always different parameters.

I think it's to do with mongodb not updating fast enough, although I'm not sure. The problem happens when two inserts to mongodb happen in quick succession.

I will post some code later.
To unsubscribe from this group and all its topics, send an email to meteor-talk+unsubscribe@googlegroups.com.

Dave Workman

unread,
Aug 15, 2014, 9:12:16 AM8/15/14
to meteo...@googlegroups.com
Is your client side update happening in a Meteor.Method or are you directly calling collection.update? Might be that your check for who's turn it is on the client says it's OK when in fact the server has timed out, it just hasn't reached the client yet. If so, either do the update in Meteor.method or do another check in coll.allow.

Andrew Mao

unread,
Aug 15, 2014, 11:02:30 AM8/15/14
to meteo...@googlegroups.com
This sounds like the write fence for the first operation not having actually committed changes to the database before the second operation starts. This is a different issue, and I've seen it as well.

Basically if you do something like Collection.insert({ foo: bar}) immediately followed by a Meteor.defer -> Collection.findOne({foo: bar}), you'll often get nothing.

Eliezer Steinbock

unread,
Aug 15, 2014, 11:21:01 AM8/15/14
to meteo...@googlegroups.com
So how do I get around that?



So here is the code I said I'd post. It looks something like this:

function pickPlayer(leagueId, playerId, teamId) {
  check(leagueId, String);
  check(playerId, String);
  check(teamId, String);

  var league = Leagues.findOne(leagueId);
  var player = Players.findOne(playerId);
  var team = Teams.findOne(teamId);

  checkPlayerPickIsValid(league, player, team);

  // add player to team
  Teams.update(teamId, {
    $addToSet: {
      playerIds: playerId
    }
  });

// if something goes wrong, we have a problem, but so far this hasn't happened as far as i'm aware.

  // check if this is the last pick of the draft
  if (league.draftPick !== league.draftOrder.length * PLAYERS_PER_TEAM) {
    // not the last pick
    Leagues.update(leagueId, {
      $addToSet: {
        draftHistory: {
          pickNo: league.draftPick,
          teamId: teamId,
          playerId: playerId
        }
      },
      $set: {
        draftPick: league.draftPick + 1,
        nextPickTill: new Date(new Date().getTime() + (league.secondsPerPick * 1000) + 1000)
      }
    });
    
    sendYourTurnEmail(league.nextPickTeam().user()._id);

    setNextPickTimeout(league._id);
  } else {
   // draft completed
  // update league, etc.
  }
}

It can be called in two places:

1) as a meteor method that the client would call:
  pickPlayer: function (leagueId, playerId, teamId) {
    pickPlayer(leagueId, playerId, teamId);
  }

2) or as in a timeout by the server where the code looks something like this:
function setNextPickTimeout() {
  var pickFunction = function () {
    pickPlayer(league._id, player._id, teamId);
  };

  pickTimeoutHandles[league._id] = Meteor.setTimeout(pickFunction, league.nextPickTill - new Date().getTime());
}

What seems to be happening is that 1 in 1000 times, pickPlayer is called twice for the same user and the checks pass both times, because my server is apparently unaware of the update to mongodb.
I believe it's when the timeout ends and the player picks at the same time, although I haven't been able to reproduce this myself yet.

Dave Workman

unread,
Aug 15, 2014, 1:33:32 PM8/15/14
to meteo...@googlegroups.com
I think this is a Fibers issue. Here's my take on what I think is happening:

Client calls pick player,
Client asks for League, Player, Team entries
During the wait time for the database to respond for those three entries the server calls and asks for those as well


client passes checkPlayerPickIsValid
server passes checkPlayerPickIsValid because it has the Team entry cached from before the client ran the update.

client runs update
server runs update

The way I'd approach this is checking in the client method that the current time is less than or equal to the time on the timeout field, and if it's the timeout check that it's greater than, and add 0.5-1 second to the timeout.

Of course I could be wrong, but that's where my instincts are pointing.

Good luck!

mk_too

unread,
Aug 15, 2014, 4:58:32 PM8/15/14
to meteo...@googlegroups.com
What is in checkPlayerPickIsValid()?  It looks like that function is failing to stop the second set of database updates where it should.  

Also, if I understand correctly, the Leagues collection ends up with duplicate 'draftHistory.pickNo' within the same leagueId.    A unique index would prevent that from happening.  Use `Leagues._ensureIndex({leagueId:1, 'draftHistory.pickNo': 1},{unique: true})` to set up the index.  After that the Leagues.update will fail if a league gets two picks with the same pickNo.  

Just to make sure you are aware, Mongo is not atomic for updates of multiple collections ( see 'two-phase commit' ).  I don't think Meteor tries to handle this issue by default.  

Mike

Eliezer Steinbock

unread,
Aug 16, 2014, 2:54:38 PM8/16/14
to meteo...@googlegroups.com
checkPlayerPickIsValid() throws an error if there's a problem with the pick. Like check(var, String) throws an error.

Thanks for the responses. I'll look into this more.

Mike, with regards to pick number being unique: I use simple-schema + collections2. I don't actually have draftHistory.pickNo set to unique at the moment so that's something I should add.
Do you happen to know if there's a need to use _ensureIndex if using simple-schema? I should look that up.

One thing I have noticed though is that simple-schema doesn't fully protect me. I can make the maxLength of an array 15, yet on very rare occasions, I find arrays of length 16.

Another problem I ran into was the following code updating draftHistory, but not updating draftPick ($addToSet worked and $set didn't):
    Leagues.update(leagueId, {
      $addToSet: {
        draftHistory: {
          pickNo: league.draftPick,
          teamId: teamId,
          playerId: playerId
        }
      },
      $set: {
        draftPick: league.draftPick + 1,
        nextPickTill: new Date(new Date().getTime() + (league.secondsPerPick * 1000) + 1000)
      }

Again, all these problems happen maybe 1 in 1000 times, but this means I'm seeing a problem every day or so due to how often these functions are called.

Eliezer Steinbock

unread,
Aug 18, 2014, 2:30:53 PM8/18/14
to meteo...@googlegroups.com
I'm not doing anything client side. The pick method is server side only and the setTimeout is also server side.

Eliezer Steinbock

unread,
Aug 18, 2014, 2:35:02 PM8/18/14
to meteo...@googlegroups.com
In response to my own question about simple-schema and _ensureIndex, see this:
https://github.com/aldeed/meteor-collection2#index-and-unique

I'm going to try this out now, but the truth is that I don't think it will help me. Teams are updated and then Leagues. Even if I protect Leagues, Teams will be updated and that will still cause problems. I'm going to have to read up about this two-phase commit.
To unsubscribe from this group and all its topics, send an email to meteor-talk+unsubscribe@googlegroups.com.

mk_too

unread,
Aug 18, 2014, 6:16:12 PM8/18/14
to meteo...@googlegroups.com
Move the Leagues update ahead of Teams.  Your code is assuming both updates always succeed ( no error handling ).  You are no worse off by changing the order.  

So you may as well put the Leagues update first and use its failure to stop the method execution when it is a duplicate.

Eliezer Steinbock

unread,
Aug 18, 2014, 6:30:20 PM8/18/14
to meteo...@googlegroups.com

Yes. Thank you. That's exactly what I was thinking tonight too

Eliezer Steinbock

unread,
Oct 13, 2014, 11:13:17 AM10/13/14
to meteo...@googlegroups.com
How does `Leagues._ensureIndex({leagueId:1, 'draftHistory.pickNo': 1},{unique: true})` work? Doesn't this guarantee uniqueness between different documents? Rather than within an array in a single document?

Eliezer Steinbock

unread,
Oct 14, 2014, 10:52:30 AM10/14/14
to meteo...@googlegroups.com
You can't ensure uniqueness in an array. You can only ensure uniqueness across documents. See here:

Eliezer Steinbock

unread,
Oct 19, 2014, 2:12:36 PM10/19/14
to meteo...@googlegroups.com
In the end this is the solution I used:

So simple. This was causing me a headache for a very long time. Hopefully it'll now be completely gone.
Reply all
Reply to author
Forward
0 new messages