Meteor-Community-Packages / meteor-collection-hooks

Meteor Collection Hooks
https://atmospherejs.com/matb33/collection-hooks
MIT License
657 stars 92 forks source link

Hooks intermittently not running #67

Closed dkoo761 closed 9 years ago

dkoo761 commented 9 years ago

I've been trying to figure out why some of my test suite has been intermittently failing and it looks like the cause is that the collection hooks are often not running.

To easily demonstrate how intermittently the hooks are running, I wrapped one of my collection update() calls with a for loop and some comments:

for (var i = 0; i < 30; i++) {
    logger.info('Challenges.update STARTED');
    Challenges.update({_id: challengeId}, {$set: challenge});
    logger.info('Challenges.update DONE');
}

When running my test suite with the above code added, the output below shows that the hooks often aren't running. As you can see, out of 8 iterations through the loop, the hook didn't run on the 2nd, 5th and 8th iterations (I omitted the rest of the loop iterations for brevity).

I20141012-17:08:06.188(-7)? info: Challenges.update STARTED
I20141012-17:08:06.194(-7)? info: Challenges.after.update....
I20141012-17:08:06.195(-7)? info: Incrementing wins for playerId=4jFy3Wip3Za26N63B
I20141012-17:08:06.200(-7)? info: Incrementing losses for playerId=9XhzGY5rKKHvS5p4k
I20141012-17:08:06.206(-7)? info: incrementing done
I20141012-17:08:06.216(-7)? info: Challenges.update DONE
I20141012-17:08:06.217(-7)? info: Challenges.update STARTED
I20141012-17:08:06.224(-7)? info: Challenges.update DONE
I20141012-17:08:06.225(-7)? info: Challenges.update STARTED
I20141012-17:08:06.233(-7)? info: Challenges.after.update....
I20141012-17:08:06.233(-7)? info: Incrementing wins for playerId=4jFy3Wip3Za26N63B
I20141012-17:08:06.237(-7)? info: Incrementing losses for playerId=9XhzGY5rKKHvS5p4k
I20141012-17:08:06.240(-7)? info: incrementing done
I20141012-17:08:06.250(-7)? info: Challenges.update DONE
I20141012-17:08:06.251(-7)? info: Challenges.update STARTED
I20141012-17:08:06.255(-7)? info: Challenges.after.update....
I20141012-17:08:06.255(-7)? info: Incrementing wins for playerId=4jFy3Wip3Za26N63B
I20141012-17:08:06.260(-7)? info: Incrementing losses for playerId=9XhzGY5rKKHvS5p4k
I20141012-17:08:06.265(-7)? info: incrementing done
I20141012-17:08:06.275(-7)? info: Challenges.update DONE
I20141012-17:08:06.275(-7)? info: Challenges.update STARTED
I20141012-17:08:06.282(-7)? info: Challenges.update DONE
I20141012-17:08:06.282(-7)? info: Challenges.update STARTED
I20141012-17:08:06.286(-7)? info: Challenges.after.update....
I20141012-17:08:06.286(-7)? info: Incrementing wins for playerId=4jFy3Wip3Za26N63B
I20141012-17:08:06.291(-7)? info: Incrementing losses for playerId=9XhzGY5rKKHvS5p4k
I20141012-17:08:06.295(-7)? info: incrementing done
I20141012-17:08:06.304(-7)? info: Challenges.update DONE
I20141012-17:08:06.304(-7)? info: Challenges.update STARTED
I20141012-17:08:06.309(-7)? info: Challenges.after.update....
I20141012-17:08:06.310(-7)? info: Incrementing wins for playerId=4jFy3Wip3Za26N63B
I20141012-17:08:06.314(-7)? info: Incrementing losses for playerId=9XhzGY5rKKHvS5p4k
I20141012-17:08:06.318(-7)? info: incrementing done
I20141012-17:08:06.325(-7)? info: Challenges.update DONE
I20141012-17:08:06.326(-7)? info: Challenges.update STARTED
I20141012-17:08:06.333(-7)? info: Challenges.update DONE
..........

Any thoughts? This looks like a pretty serious bug :( I don't remember having this problem before the upgrade to Meteor 0.9.x if that helps at all. I'm currently on Meteor 0.9.3.1 and collection-hooks 0.7.6.

dkoo761 commented 9 years ago

I also tried removing all the code in the Challenges.after.update() hook except a 1-line comment to make sure there was nothing in my hook code that was causing this but the problem is still there.

dkoo761 commented 9 years ago

FYI, I have replaced the collection hook I was using on my Challenges collection with a simple function that I manually call after each update to that collection (and copy/pasted the code from the collection hook into the new function) and this works fine for now. So it does look to be a bug in the collection-hooks package. Until this issue is resolved, I will do the same with my other collection hooks.

Also, I'm using the following collection-related packages if this helps troubleshooting:

aldeed:collection2@2.1.0 aldeed:simple-schema@1.0.3

matb33 commented 9 years ago

If you don't use collection2 and/or simple-schema, do your hooks get called correctly?

dkoo761 commented 9 years ago

I'm not sure. I've already removed all the collection hooks and replaced with my own function calls since my app is in production and requires the functionality in those hooks to work properly. I'll give it a try without collection2 and/or simple-schema when I get some time in the next few days and let you know.

Were you able to replicate the issue using a simple for loop like I provided?

On Sun, Oct 12, 2014 at 8:23 PM, Mathieu Bouchard notifications@github.com wrote:

If you don't use collection2 and/or simple-schema, do your hooks get called correctly?

— Reply to this email directly or view it on GitHub https://github.com/matb33/meteor-collection-hooks/issues/67#issuecomment-58840130 .

Lepozepo commented 9 years ago

I had a similar issue but it was only failing intermittently on .after.update.

matb33 commented 9 years ago

The hooks are running properly according to my test:

https://github.com/matb33/meteor-collection-hooks/blob/issue67/tests/hooks_in_loop.js

Something in collection2 and/or simple-schema is interfering with collection-hooks.