Skip to content

Instantly share code, notes, and snippets.

@jlfwong

jlfwong/RequireJSsubprocess.md

Created September 29, 2013 19:24
Show Gist options
  • Save jlfwong/6755667 to your computer and use it in GitHub Desktop.
Save jlfwong/6755667 to your computer and use it in GitHub Desktop.
Download ZIP
Require JS Subprocess Rubber Ducky Log
Raw
RequireJSsubprocess.md

Building the package! RequireJS plugin, I'm getting weird side effect problems.

Requiring a package first:

> require(["package!issues.js"]); null
null
Require Package: issues.js package_loader_plugin.js?bust=1379092758956:96
XHR finished loading: "http://localhost:1234/javascript-packages.json".
jquery.js?bust=1379092758956:8526
Require Package: react.js package_loader_plugin.js?bust=1379092758956:96
Uncaught Error: Load timeout for modules:
package!issues.js_unnormalized2,package!issues.js,package!react.js,/javascript/react-package/react.js,jsx!/javascript/react-package/userhoverable.jsx_unnormalized3,jsx!/javascript/react-package/timeago.jsx_unnormalized4,jsx!/javascript/react-package/extras.jsx_unnormalized5,javascript/react-package/JSXTransformer
http://requirejs.org/docs/errors.html#timeout require.js:8
> require(["jsx!/javascript/issues-package/issues.jsx"]); null
null
> require(["package!issues.js"]); null
null

Requiring a JSX file first:

> require(["jsx!/javascript/issues-package/issues.jsx"]); null
null
Require JSX: /javascript/issues-package/issues.jsx
jsx_loader_plugin.js?bust=1379092854268:41
XHR finished loading:
"http://localhost:1234/javascript/issues-package/issues.jsx?bust=1379092854268".
jquery.js?bust=1379092854268:8526
> require(["package!issues.js"]); null
null
Require Package: issues.js package_loader_plugin.js?bust=1379092854268:96
XHR finished loading: "http://localhost:1234/javascript-packages.json".
jquery.js?bust=1379092854268:8526
Require Package: react.js package_loader_plugin.js?bust=1379092854268:96
Require JSX: /javascript/react-package/userhoverable.jsx
jsx_loader_plugin.js?bust=1379092854268:41
Require JSX: /javascript/react-package/timeago.jsx
jsx_loader_plugin.js?bust=1379092854268:41
Require JSX: /javascript/react-package/extras.jsx
jsx_loader_plugin.js?bust=1379092854268:41
XHR finished loading:
"http://localhost:1234/javascript/react-package/userhoverable.jsx?bust=1379092854268".
jquery.js?bust=1379092854268:8526
XHR finished loading:
"http://localhost:1234/javascript/react-package/timeago.jsx?bust=1379092854268".
jquery.js?bust=1379092854268:8526
XHR finished loading:
"http://localhost:1234/javascript/react-package/extras.jsx?bust=1379092854268".
jquery.js?bust=1379092854268:8526
Uncaught Error: Load timeout for modules:
package!issues.js_unnormalized3,package!issues.js,package!react.js,/javascript/react-package/JSXTransformer.js,/javascript/react-package/react.js
http://requirejs.org/docs/errors.html#timeout

In both cases, it's timeing out and spitting out some garbage about _unnormalized. No idea what's going on here.

It doesn't seem to happen for all packages. The react.js package seems to work just fine, but the issues.js package screws up.

It's also not all packages that depend on react.js. perseus.js seems to work.

shared.js doesn't work.

TODO: Just try all packages and try to find the common ground between the failures. Also try hopping on IRC or bugging the mailing lists to see wtf is going on.

If I empty the files part of the issues.js package, it loads fine. Having either issues.jsx or i18n-form.jsx both make it fail.

Adding jquery as one of the files works...

Adding a .jsx file from a different package fails...

Just requiring "jsx!/javascript/clarifications-package/official.jsx";

Directly fails. Progress!

But requiring "jsx!/javascript/issues-package/issues.jsx" works fine.

...Unless the react package has already been loaded.

This fails even if the jsx file being included is empty.

Using these to debug:

window.drr = function(pkg) {
    require(["package!react.js"], function() {
        dr(pkg);
    });
};

window.dr = function(pkg) {
    require([pkg], function(x) { console.log("Success", x); });
};

When the react.js package is empty, it loads fine.

When it contains /javascript/react-package/react.js it breaks.

When it contains ../shared-package/jquery.js it works fine...

Looks like it might have nothing to do with JSX at all?

"react.js": {
    "files": [
        "../../third_party/javascript-khansrc/console-polyfill/index.js",
        "react.js"
    ]
}

dr("package!react.js");

Works, but

"react.js": {
    "files": [
        "react.js"
    ]
},

dr("package!react.js");
Uncaught Error: Load timeout for modules: package!react.js_unnormalized2,package!react.js,/javascript/react-package/react.js

D'oh, I left this in:

req([_.first(requirePathsForPackage(package, name))], function() {
    onload(package);
});

Changing it back to

req(requirePathsForPackage(package, name), function() {
    onload(package);
});

Results in the failure regardless of the presence of the console shim.

Looks like it's got nothing to do with package loading at all.

dr("/javascript/react-package/react.js");

Also fails.

Voila! Minimal test case:

> require(["/javascript/react-package/react.js"]); null
null
Uncaught Error: Load timeout for modules: /javascript/react-package/react.js
http://requirejs.org/docs/errors.html#timeout

Augghhh. I actually was running into case 3 of the timeout problems.

Real minimal test case:

require("javascript/react-package/react");
require("/javascript/react-package/react.js");

Finally got tests that load the entire shared package running in the browser, and now phantomjs is choking.

TypeError: 'undefined' is not a function (evaluating 'RegExp.prototype.test.bind(
    /^(data|aria)-[a-z_][a-z\d_.\-]*$/
)')

Very confused as to how this happens in phantom, but not chrome. Different versions of V8? Wtf?

Changing it to this seems to fix the problem:

isCustomAttribute: function(name) {
    return /^(data|aria)-[a-z_][a-z\d_.\-]*$/.test(name);
},

But now I'm getting failures that I don't see in the browser.

Error: Load timeout for modules: package!dashboard.js_unnormalized2,package!dashboard.js,package!profile.js,template!profile.profile-tab-achievements
http://requirejs.org/docs/errors.html#timeout
http://localhost:1235/third_party/javascript-khansrc/requirejs/require.js : 138
http://localhost:1235/third_party/javascript-khansrc/requirejs/require.js : 536
http://localhost:1235/third_party/javascript-khansrc/requirejs/require.js : 691
http://localhost:1235/third_party/javascript-khansrc/requirejs/require.js : 710
Timeout: tests did not start. This may be because of errors on the page.

It seems to choke on

require("package!dashboard.js");

shared.js and tasks.js both load just fine.

it chokes on profile.js

dashboard.js without the dependency on profile.js seems to work, so that suggests the problem is in profile.js

When requiring profile.js:

(khan27)[~/khan/webapp] (jlfwong-package-require-testinfra [staged][untracked]) tools/runjstests.py javascript/tasks-package/
JQMIGRATE: Logging is active
Error: Load timeout for modules: package!profile.js_unnormalized2,package!profile.js,template!profile.profile-tab-questions
http://requirejs.org/docs/errors.html#timeout
http://localhost:1235/third_party/javascript-khansrc/requirejs/require.js : 138
http://localhost:1235/third_party/javascript-khansrc/requirejs/require.js : 536
http://localhost:1235/third_party/javascript-khansrc/requirejs/require.js : 691
http://localhost:1235/third_party/javascript-khansrc/requirejs/require.js : 710

Removing all of the following from the profile.js package fixes the problem:

"profile-tab-discussion.handlebars",
"profile-tab-questions.handlebars",
"profile-tab-recommendations.handlebars",
"profile-tab-coaches.handlebars",
"profile-tab-explorations.handlebars",
"profile-tab-user-profile.handlebars"

Frustratingly, removing everything except for those handlebars templates also fixes things.

After thinking on it a while longer, I remembered that phantomjs is built on webkit, not chromium, so it's actually using JavascriptCore, not V8. Still, I tried loading up the tests in Safari, and they still work. So there's still a disparity between WebKit and phantom.

Narrowing down the file selection in the package, it seems like it might just be the sheer number of files that's causing phantom to choke. Weird...

On an unrelated note, perhaps I should scrap the work I previously did and replace it as much as possible with Karma: http://karma-runner.github.io/0.10/intro/configuration.html

It has out of the box support for Mocha, which is super awesome. It also has support for PhantomJS and Require. The more I read, the more I think I should scrap what I did. As far as I can tell, however, the package require problem is completely orthogonal to the testrunner to use.

Searching around, this also seems like it could be a pretty sweet tool for code coverage in JS: http://blanketjs.org/

Theory: the problem is the sheer number of files.

If I stop package loading from autoloading shared.js, it fixes the problem. This supports said theory.

If I make a package containing 150 files and load only that, it also fails, and only in phantomjs. Regardless of the dependency on shared.js.

The crossover point seems to be 120 files. 119 works fine.

As a sanity check, I tried increasing the RequireJS timeout to be 10 seconds instead of 1, and it still failed. This suggests that this is not a real timeout.

If I switch to using a regular require instead of my forced serialization of package requires using deferred, the error seems to go away.

Using the serialized approach, it literally seems to give up after 119:

...
LOADED:  /javascript/foobar-package/x111.js
LOADED:  /javascript/foobar-package/x112.js
LOADED:  /javascript/foobar-package/x113.js
LOADED:  /javascript/foobar-package/x114.js
LOADED:  /javascript/foobar-package/x115.js
LOADED:  /javascript/foobar-package/x116.js
LOADED:  /javascript/foobar-package/x117.js
LOADED:  /javascript/foobar-package/x118.js
LOADED:  /javascript/foobar-package/x119.js
Error: Load timeout for modules: package!foobar.js_unnormalized2,package!foobar.js,/javascript/foobar-package/x120.js
http://requirejs.org/docs/errors.html#timeout
   http://localhost:1235/third_party/javascript-khansrc/requirejs/require.js : 138
   http://localhost:1235/third_party/javascript-khansrc/requirejs/require.js : 536
   http://localhost:1235/third_party/javascript-khansrc/requirejs/require.js : 691
   http://localhost:1235/third_party/javascript-khansrc/requirejs/require.js : 710

Now trying a parallelized, but still Deferred approach, it also fails at x120. Perhaps this is a bug/limitation of jQuery Deferreds?

Switching to another async task that doesn't use require, it passes using 200 Deferreds, so that seems like an unlikely cause.

Switching to AJAX get requests instead of RequireJS at all seems to yield similar problems, though it happens with a higher number of requests. Let's see if I can construct a smaller test case.

Trying to pull it out into its own reduced repo isn't reproducing, and even pulling it out into the index.html of the test runner isn't reproducing...

Pulling it out of the test file into the main require entry point will reproduce, but with a higher number. I should try using requirejs in the other system and see if that reproduces.

It also doesn't appear to matter if they're actually different files. Unique query strings seems to repro as well...

It doesn't seem to depend on it being a js file either. Changing the file extension and the datatype don't prevent the bug from being reproducible.

It also doesn't appear to depend on the contents of the file at all. It doesn't even affect the number of success loads before the blocking.

When writing the isolated test case it's evident that phantom does pause after a certain number of calls (probably for GC), but it picks up again eventually. It doesn't seem to even pick up again in the failure case.

I can get the same behaviour using $.getScript(), which means that this isn't something RequireJS specific. Still can't repro it in a totally isolated environment.

Running the static server and phantomjs script manually, it looks like the bug doesn't repro. Could this be something crazy like ulimit on subprocesses?

YES! Got a repro in a separate repo.

It seems to have nothing to do with deferreds either. Just running phantomjs in a subprocess.

For whatever reason, I can only reproduce if both the SimpleHTTPServer AND the phantom process are invoked using subprocess. If I invoke either one outside, it seems to work just fine...

The number of requests that sucessfully go through is consistent, so that suggests it's a hard limit somewhere.

...and then it magically started working again.

Okay, it seems to only happen when stderr=subprocess.PIPE is set on the subprocess call to SimpleHTTPServer. Is the pipe full?

Augh yes, the pipe is full. http://thraxil.org/users/anders/posts/2008/03/13/Subprocess-Hanging-PIPE-is-your-enemy/

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment