[0.12.1] Callback already called / hook 'moduleloader' is taking too long to load.

[Salakar]

I think this issue is related to #3550. I upgraded to 0.12.1 from 11 to see if https://github.com/balderdashy/sails-hook-sockets/issues/16 had been fixed.

Lift is successful, with all the hooks in the rc below not loading as intended. But after a while I get the module loader hook timeout and a callback already called error from here: https://github.com/balderdashy/sails/blob/master/lib/app/private/loadHooks.js#L87

Error:

Scope at the point of error:

Same issue occurs via https://github.com/Jam3/devtool (as above) or just using pure node.

Node version: v5.6.0
Electron version: v0.36.8

.sailsrc:

{
  "hooks": {
    "csrf": false,
    "grunt": false,
    "i18n": false,
    "pubsub": false,
    "controllers": false,
    "request": false,
    "session": false,
    "sockets": false,
    "http": false,
    "views": false,
    "middleware": false,
    "router": false,
    "express": false,
    "responses": false,
    "policies": false,
    "blueprints": false,
    "cors": false
  }
}

@luislobo tagging you in as you did the original PR.

[mikermcneil]

@Salakar awesome explanation- thank you. Will take a look ASAP.

In the mean time, some notes:

• This commit was for 0.11.5, so at first I thought this might just be that we need to make a comparable change to master. But looks like the fix is in place on master as well. So there's probably something else going on..
• @sgress454 merged @luislobo's patch into stable, which is now the 0.11 branch (since 0.12.x is the stable release now). See https://github.com/balderdashy/sails/commits/0.11 for context.

[Salakar]

Some more notes:

• Always errors 10 times (10 modules?):
  
• Also only occurs in debugger. node debug / devtool - can't reproduce issue without debug mode. Weirdly. Potentially looks like the clearTimeout stuff isn't working. So I guess this is not a production issue - just an annoyance during development. Sails continues fine after all the errors have been thrown.
• Did a global node modules wipe, and a project node modules wipe. Same issue.
• Exact version I upgraded from was 0.11.4, had no issues on this version. Will try roll back to this, and then test 11.5 & 12 subsequently.

[Salakar]

Ok, I rolled back to 11.4 still having the same issue. So must be something my side, closing this for now until I can investigate further. Danke.

[moisesrodriguez]

I'm getting a similar error on 12.1

Error: A hook (`orm`) failed to load!
 Error: Callback was already called.
     at /web/backend/node_modules/sails/node_modules/async/lib/async.js:43:36
     at /web/backend/node_modules/sails/lib/app/private/loadHooks.js:99:18
     at /web/backend/node_modules/sails/node_modules/async/lib/async.js:52:16
     at /web/backend/node_modules/sails/node_modules/async/lib/async.js:565:21
     at /web/backend/node_modules/sails/node_modules/async/lib/async.js:167:37
     at /web/backend/node_modules/sails/lib/hooks/orm/build-orm.js:53:23
     at /web/backend/node_modules/sails/node_modules/waterline/lib/waterline.js:208:23
     at /web/backend/node_modules/sails/node_modules/waterline/node_modules/async/lib/async.js:52:16
     at /web/backend/node_modules/sails/node_modules/waterline/node_modules/async/lib/async.js:264:21
     at /web/backend/node_modules/sails/node_modules/waterline/node_modules/async/lib/async.js:44:16
     at /web/backend/node_modules/sails/node_modules/waterline/lib/waterline/query/index.js:68:23
     at null._onTimeout (/web/backend/node_modules/sails/node_modules/waterline/lib/waterline/adapter/sync/strategies/alter.js:268:12)
     at Timer.listOnTimeout (timers.js:92:15)
 freetype.js:1
 var Module;if(typeof Module==="undefined")Module=eval("(function() { try { return Module || {} } catch(e) { return {} } })()");if(!Module.expectedDataFileDownloads){Module.expectedDataFileDownloads=0;Module.finishedDataFileDownloads=0}Module.expectedDataFileDownloads++;((function(){function runWithFS(){function assert(check,msg){if(!check)throw msg+(new Error).stack}fileData0=[];fileData0.push.apply(fileData0,[79,84,84,79,0,13,0,128,0,3,0,80,67,70,70,32,137,224,82,238,0,0,7,132,0,0,45,223,70,70,84,77,101,130,23,249,0,0,55,12,0,0,0,28,71,68,69,70,0,160,0,4,0,0,53,100,0,0,0,32,71,80,79,83,184,255,184,254,0,0,54,220,0,0,0,48,71,83,85,66,234,147,151,221,0,0,53,132,0,0,1,88,79,83,47,50,131,156,137,79,0,0,1,64,0,0,0,96,99,109,97,112,146,230,183,142,0,0,5,184,0,0,1,170,104,101,97,100,251,7,171,9,0,0,0,220,0,0,0,54,104,104,101,97,7,42,2,2,0,0,1,20,0,0,0,36,104,109,116,120,33,252,29,155,0,0,55,40,0,0,0,234,109,97,120,112,0,115,80,0,0,0,1,56,0,0,0,6,110,97,109,101,152,108,186,46,0,0,1,160,0,0,4,23,112,1
 Error: Callback was already called.
     at /web/backend/node_modules/sails/node_modules/async/lib/async.js:43:36
     at /web/backend/node_modules/sails/lib/app/private/loadHooks.js:99:18
     at /web/backend/node_modules/sails/node_modules/async/lib/async.js:52:16
     at /web/backend/node_modules/sails/node_modules/async/lib/async.js:565:21
     at /web/backend/node_modules/sails/node_modules/async/lib/async.js:167:37
     at /web/backend/node_modules/sails/lib/hooks/orm/build-orm.js:53:23
     at /web/backend/node_modules/sails/node_modules/waterline/lib/waterline.js:208:23
     at /web/backend/node_modules/sails/node_modules/waterline/node_modules/async/lib/async.js:52:16
     at /web/backend/node_modules/sails/node_modules/waterline/node_modules/async/lib/async.js:264:21
     at /web/backend/node_modules/sails/node_modules/waterline/node_modules/async/lib/async.js:44:16
     at /web/backend/node_modules/sails/node_modules/waterline/lib/waterline/query/index.js:68:23
     at null._onTimeout (/web/backend/node_modules/sails/node_modules/waterline/lib/waterline/adapter/sync/strategies/alter.js:268:12)
     at Timer.listOnTimeout (timers.js:92:15)

It seems to only happen to me when I run models.js as alter. But it runs and the sails continues to run normally.

[moisesrodriguez]

Nevermind, in my specific case it was that I had to increase the hookTimeout when running in alter mode.