[TIMOB-24293] Alloy: iOS - Using require() without "/" prefix will try to load file relatively node_modules first, other unrelated logs and behavior changes
| GitHub Issue | n/a |
|---|---|
| Type | Bug |
| Priority | Critical |
| Status | Closed |
| Resolution | Duplicate |
| Resolution Date | 2017-05-02T17:21:37.000+0000 |
| Affected Version/s | Release 6.0.0, Release 6.0.1 |
| Fix Version/s | Release 6.1.0 |
| Components | iOS |
| Labels | merge-6.0.2, require |
| Reporter | Rene Pot |
| Assignee | Feon Sua Xin Miao |
| Created | 2017-01-11T13:07:26.000+0000 |
| Updated | 2017-05-02T17:21:37.000+0000 |
Description
We're using a lot of requires in the app. Also with databinding we use require for every row. This used to work great with 5.# but now it seems to try something else. It tries to load the node_module first, then tries to find the controller/lib file resulting in a log like this:
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/node_modules/libs/Location, Resource: node_modules/libs/Location
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/node_modules/libs/Location.js, Resource: node_modules/libs/Location_js
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/node_modules/libs/Location.json, Resource: node_modules/libs/Location_json
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/node_modules/libs/Location/package.json, Resource: node_modules/libs/Location/package_json
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/node_modules/libs/Location/index.js, Resource: node_modules/libs/Location/index_js
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/node_modules/libs/Location/index.json, Resource: node_modules/libs/Location/index_json
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/node_modules/libs/Location, Resource: node_modules/libs/Location
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/node_modules/libs/Location.js, Resource: node_modules/libs/Location_js
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/node_modules/libs/Location.json, Resource: node_modules/libs/Location_json
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/node_modules/libs/Location/package.json, Resource: node_modules/libs/Location/package_json
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/node_modules/libs/Location/index.js, Resource: node_modules/libs/Location/index_js
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/node_modules/libs/Location/index.json, Resource: node_modules/libs/Location/index_json
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/libs/Location, Resource: libs/Location
[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/34E19F4B-9A68-48FC-BA03-2A5B02D168BE/Roamler.app/libs/Location.js, Resource: libs/Location_js
require('libs/location.js');require('/libs/location.js');
[~cbarber] cb-tooling?
There is no workaround for
This is generated to be a require without a prefixed slash. And it does try to load node_modules first even if I add a prefixed slash to the src.I doubt this is a tooling thing. [~cwilliams] did you touch
require()on iOS? Any idea?Here is an example of this behavior: app.js
var win = Ti.UI.createWindow({ backgroundColor: '#fff' }); var btn = Ti.UI.createButton({ title: 'Trigger' }); btn.addEventListener('click', function() { var more = require('more'); alert(more.test); }); win.add(btn); win.open();And the output when hitting the trigger button once (!):So the effort here would be to detect the correct location earlier to prevent the above file operations that cause the app to slow down as described. The behavior can be debugged by setting a break-point [here](https://github.com/appcelerator/titanium_mobile/blob/master/iphone/Classes/KrollBridge.m#L916) andpo pathto the see path. The log is generated by theloadAppResourcemethod.More test-cases incoming! Using my open-sourced canteen app (), there are 10x more logs in 6.0.1.GA compared to 5.5.1.GA: - 6.0.1.GA: https://gist.github.com/hansemannn/104345f36377cfd434c967e379ae2347 - 5.5.1.GA: https://gist.github.com/hansemannn/ab1f0e0978a393064846a1ffc13c59ba I also noted the following other differences: 5.5.1.GA:
6.0.1.GA:-- Start simulator log ------------------------------------------------------- [DEBUG] Loading: /Users/hknoechel/Library/Developer/CoreSimulator/Devices/B1E64A97-DC1C-482D-BA35-CCC66CFF1479/data/Containers/Bundle/Application/EECBC008-0CA2-47B5-9A0B-EA022A8A89E7/Mensa.app/lloy/controllers/lunches/node_modules/alloy.js, Resource: lloy/controllers/lunches/node_modules/alloy_js [DEBUG] {"tiSDKVersion":"6.0.1","githash":"__GITHASH__","deployType":"development","appId":"de.hansknoechel.mensaapp","version":"3.0.0","guid":"46ee97ea-53fa-43fe-9888-47e86daea053","name":"Mensa"}Lets keep in mind it also slows down the app massively and is possibly blocking a release with 6.0.1 because we use a LOT of requires in our app (lots of alloy requires inside xml files). Will this please be released as a hotfix of 6.0.1?
This is not a tooling thing. This is intentional - we changed require behavior to be more in line with Node.JS/CommonJS style. When we run into an un-prefixed path we don't know if it's intentionally un-prefixed or not, and we need to try and preserve the ability to handle un-prefixed paths as we did before when it isn't. So If it's a single path segment that's un-prefixed - yeah we will attempt to see if it's a core(read: native) module first, then we'll see if it's a CommonJS module, then we'll try and see if it might be a node_module, and lastly we'll fall back to legacy Titanium behavior of assuming it's actually intended to be an "absolute" path with no prefix. Form Hans' logs above, I see a bug in that we appear to be checking the node_modules area twice - if that's consistent, that is a bug to be fixed. We should update alloy to generate prefixed paths in Titanium 6+, to help trim the possibility set of where we look (and I think we already have a ticket for this). I think it'd also be useful to gather a little more timing data to see what slowdowns this may be causing and where exactly. Looking at Hans's logs above it appears that the "misses" look to be taking roughly 1/3 to 1/4ms each, which doesn't seem huge to me. But I **do** see a major slowdown between the node_modules check to the legacy fallback of ~4.5s - is that just an aberration, or consistent?
A common functionality is to have a transform function with data binding. Within this transform function we call a couple methods from lib files. Without it actually being specified a big listview (with hundreds of models) caused delays of 1-2 seconds compared to previously. With the leading
/it was fixed. Another common problem, where we have a lot in the app, is using require inside the xml files. These try the same functionality and there it is impossible to fix it ourselves. With big views, and loads of requires, that too caused big delays for us. This in combination with each other made a very slow app. If the leading "/" is a requirement now it should also work with Alloy XML files and communicated clearly as a breaking change. Until now it was never communicated it was a requirement, and if my memory is correct it at first didn't even work correctly in the past. The blogpost for 6.0 didn't mention this, and in the releasenotes nothing is told about it being required if you want to keep performance high, only it will fall back to the default. So conclusion, for a couple requires it is not that bad, but many apps use A LOT, which slows down the app massivelyI'm sad this ticket didn't make it into 6.0.2. It really is a critical thing. This also happens for any require inside an alloy view. So if you use a require in, say, a controller for a row in tableview, a tableview filled with 100 items will trigger 100 times... every time. It is heavily slowing down everything in the app
Alloy.createController = function(name, args) { return new (require("/alloy/controllers/" + name))(args); }; Alloy.createModel = function(name, args) { return new (require("/alloy/models/" + ucfirst(name)).Model)(args); }; Alloy.createCollection = function(name, args) { return new (require("/alloy/models/" + ucfirst(name)).Collection)(args); };[DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/2BD2A8E3-6D77-4476-AADA-097C7D2FB7A2/Roamler.app/libs/Utils/Display, Resource: libs/Utils/Display [DEBUG] : Loading: /Users/renepot/Library/Developer/CoreSimulator/Devices/58DEF941-13A4-4852-A765-F23042B1F82B/data/Containers/Bundle/Application/2BD2A8E3-6D77-4476-AADA-097C7D2FB7A2/Roamler.app/libs/Utils/Display.js, Resource: libs/Utils/Display_jsThis adjustment to the createController function made it, compared to above, blazing fast:
var requiredControllers = {}; Alloy.createController = function(name, args) { if (!requiredControllers[name]){ requiredControllers[name] = require("/alloy/controllers/" + name); } return new (requiredControllers[name])(args); };[~topener] Have this changes been included in require-fix Alloy PR from recently? I remember you said something related. Thanks man!
Although there is a performance hit with searching for the module, I would not want to vary at from looking in node_modules first, if the '/' prefix is not used, as this is the way nodejs resolves module locations. A lot of the performance issues could be handled at compile time (instead of at runtime). See nativeloop (https://github.com/nativeloop/nativeloop) for an example of resolving module paths at compile time.
Fixed by ALOY-1523.