Browser performance issue on iterative property access #45
Comments
|
3s is long indeed. However, are we sure it is an LDflex problem? Because the above involves (independently of whether you are using LDflex or not) fetching 70 resources over HTTP. I suspect those are the source of the 10–90ms delay. A solution would be to parallelize the |
|
When I inspect the network requests, as all the resources are in the 1rst graph, only one request to |
|
I see; the |
|
Ah ah, cool!!! |
|
Hi @RubenVerborgh, Any news here? This one is a priority for us since it is turning our apps into lazy slugs :) |
Any profiling or insights where time is being spent, would help me get this solved faster. Booked time for this early next week. |
|
I don't know if it helps but here are some observations: await solid.data.context.extend(base_context)
const resource = solid.data["https://apiprod.happy-dev.fr/clients/1/"];
console.time();
await resource.name;
console.timeEnd(); // first call, need to request server: ~150-200ms
console.time();
await resource.img;
console.timeEnd(); // no need to request server: ~10ms
console.time();
await resource['http://happy-dev.fr/owl/#img']; // with full path, same time to resolve: ~10ms
console.timeEnd();
// same observations with this syntax
console.time();
const name = await solid.data["https://apiprod.happy-dev.fr/clients/2/"].name;
console.log(name.toString());
console.timeEnd(); // ~200ms
console.time();
const img = await solid.data["https://apiprod.happy-dev.fr/clients/2/"].img;
console.log(img.toString());
console.timeEnd(); // ~10ms // and same without extending our context
const res = solid.data["https://apiprod.happy-dev.fr/clients/3/"];
console.time();
console.log((await res['rdfs:label']).toString());
console.timeEnd(); // ~200ms
console.time();
console.log((await res['http://happy-dev.fr/owl/#img']).toString());
console.timeEnd(); // ~10ms |
|
This is interesting indeed, looks like we're chasing some specific requests in particular. Thanks. |
|
When testing the "without extending our context" example, I get consistently good performance in Node.js 12.6.0: https://apiprod.happy-dev.fr/clients/: 445.242mshttps://apiprod.happy-dev.fr/clients/1/: 2.918ms https://apiprod.happy-dev.fr/clients/2/: 1.596ms https://apiprod.happy-dev.fr/clients/3/: 1.518ms https://apiprod.happy-dev.fr/clients/4/: 1.481ms https://apiprod.happy-dev.fr/clients/5/: 1.806ms https://apiprod.happy-dev.fr/clients/6/: 1.760ms https://apiprod.happy-dev.fr/clients/7/: 1.465ms https://apiprod.happy-dev.fr/clients/8/: 1.302ms https://apiprod.happy-dev.fr/clients/9/: 1.230ms https://apiprod.happy-dev.fr/clients/10/: 1.301ms https://apiprod.happy-dev.fr/clients/11/: 1.234ms https://apiprod.happy-dev.fr/clients/12/: 1.222ms https://apiprod.happy-dev.fr/clients/13/: 1.556ms https://apiprod.happy-dev.fr/clients/14/: 1.379ms https://apiprod.happy-dev.fr/clients/15/: 3.331ms https://apiprod.happy-dev.fr/clients/16/: 1.756ms https://apiprod.happy-dev.fr/clients/17/: 1.573ms https://apiprod.happy-dev.fr/clients/18/: 1.355ms https://apiprod.happy-dev.fr/clients/19/: 1.262ms https://apiprod.happy-dev.fr/clients/20/: 1.478ms https://apiprod.happy-dev.fr/clients/21/: 1.408ms https://apiprod.happy-dev.fr/clients/22/: 1.378ms https://apiprod.happy-dev.fr/clients/23/: 1.483ms https://apiprod.happy-dev.fr/clients/24/: 1.281ms https://apiprod.happy-dev.fr/clients/25/: 1.314ms https://apiprod.happy-dev.fr/clients/26/: 2.273ms https://apiprod.happy-dev.fr/clients/27/: 1.299ms https://apiprod.happy-dev.fr/clients/28/: 1.477ms https://apiprod.happy-dev.fr/clients/29/: 1.282ms https://apiprod.happy-dev.fr/clients/30/: 1.580ms https://apiprod.happy-dev.fr/clients/31/: 1.331ms https://apiprod.happy-dev.fr/clients/32/: 3.948ms https://apiprod.happy-dev.fr/clients/33/: 1.317ms https://apiprod.happy-dev.fr/clients/34/: 1.268ms https://apiprod.happy-dev.fr/clients/35/: 1.332ms https://apiprod.happy-dev.fr/clients/36/: 1.316ms https://apiprod.happy-dev.fr/clients/37/: 1.244ms https://apiprod.happy-dev.fr/clients/38/: 1.394ms https://apiprod.happy-dev.fr/clients/39/: 1.330ms https://apiprod.happy-dev.fr/clients/40/: 1.471ms https://apiprod.happy-dev.fr/clients/41/: 1.430ms https://apiprod.happy-dev.fr/clients/42/: 1.130ms https://apiprod.happy-dev.fr/clients/43/: 1.132ms https://apiprod.happy-dev.fr/clients/44/: 1.092ms https://apiprod.happy-dev.fr/clients/46/: 1.167ms https://apiprod.happy-dev.fr/clients/47/: 1.102ms https://apiprod.happy-dev.fr/clients/48/: 1.127ms https://apiprod.happy-dev.fr/clients/49/: 1.108ms https://apiprod.happy-dev.fr/clients/50/: 1.078ms https://apiprod.happy-dev.fr/clients/51/: 1.099ms https://apiprod.happy-dev.fr/clients/52/: 1.130ms https://apiprod.happy-dev.fr/clients/53/: 1.099ms https://apiprod.happy-dev.fr/clients/54/: 1.086ms https://apiprod.happy-dev.fr/clients/57/: 1.298ms https://apiprod.happy-dev.fr/clients/58/: 1.237ms https://apiprod.happy-dev.fr/clients/59/: 1.181ms https://apiprod.happy-dev.fr/clients/61/: 1.307ms https://apiprod.happy-dev.fr/clients/63/: 1.446ms https://apiprod.happy-dev.fr/clients/64/: 2.788ms https://apiprod.happy-dev.fr/clients/65/: 1.138ms https://apiprod.happy-dev.fr/clients/66/: 1.084ms https://apiprod.happy-dev.fr/clients/67/: 1.031ms https://apiprod.happy-dev.fr/clients/68/: 1.433ms https://apiprod.happy-dev.fr/clients/69/: 1.071ms https://apiprod.happy-dev.fr/clients/70/: 0.975ms https://apiprod.happy-dev.fr/clients/72/: 0.947ms https://apiprod.happy-dev.fr/clients/73/: 0.937ms https://apiprod.happy-dev.fr/clients/75/: 0.936ms https://apiprod.happy-dev.fr/clients/76/: 1.142ms https://apiprod.happy-dev.fr/clients/77/: 0.993ms https://apiprod.happy-dev.fr/clients/78/: 1.033ms https://apiprod.happy-dev.fr/clients/79/: 1.311ms https://apiprod.happy-dev.fr/clients/: 445.242ms So two questions:
|
|
I am testing in a browser (Chrome 78). Without extending our context, with this code: const container = solid.data["https://apiprod.happy-dev.fr/clients/"];
console.time(container.toString())
for await (const r of container.ldp_contains) {
console.time(r.toString())
await r['rdfs:label']
console.timeEnd(r.toString())
}
console.timeEnd(container.toString())I get different results than yours: https://apiprod.happy-dev.fr/clients/: 1088.90087890625msHere is the context I used: const base_context = {
'@vocab': 'http://happy-dev.fr/owl/#',
rdf: 'http://www.w3.org/1999/02/22-rdf-syntax-ns#',
rdfs: 'http://www.w3.org/2000/01/rdf-schema#',
ldp: 'http://www.w3.org/ns/ldp#',
foaf: 'http://xmlns.com/foaf/0.1/',
name: 'rdfs:label',
acl: 'http://www.w3.org/ns/auth/acl#',
permissions: 'acl:accessControl',
mode: 'acl:mode',
email: 'http://happy-dev.fr/owl/#email',
}; |
|
Thanks, will test on Chrome! Although it's the same V8 engine, so I wonder what goes wrong. |
|
Slower timings in Chrome and Firefox confirmed. |
|
Added comparative tests to the branch https://github.com/solid/query-ldflex/tree/test/45-performance. Run in node with I've traced the problem back to Comunica: it is the |
|
My first suspect was transpiling: perhaps the transpiled version of asynchronous iteration is slower than the native version. However, the same transpiled version is used for browsers and Node.js (I expect this to be the case all the way down Comunica as well). So I suspect the problem is rather in a shim. |
|
Thank @RubenVerborgh for your time here. @rubensworks, @joachimvh: Let us know if we can help you finding out why the |
|
@rubensworks, @joachimvh: Any good news you would like to share with us? :-) |
I think it is a shim or polyfill indeed. If you could identify the different code being called in command-line or browser, that would definitely help. Once possible example could be doing a loop of 1000 |
|
I just did the above; I see a quite some time spent in |
|
@matthieu-fesselier: If you have any further insight that might help... |
|
Indeed, the function is not supported by both Chrome and Firefox : https://developer.mozilla.org/en-US/docs/Web/API/Window/setImmediate I'll dig deeper tomorrow afternoon. |
I have sketched a possible solution here: LDflex/LDflex#44 While this does not address the root cause (= queries have an overhead in browsers), it will reduce the number of queries overall. We have not hit the threshold of a problematic number of queries in Node.js yet (I think 145ms for 180 SPARQL queries is quite acceptable), but we will eventually hit that point if more queries are needed (as do similar solutions like ActiveRecord). In parallel, we can look at what is slowing down browsers. |
|
Testing progress: the branch https://github.com/solid/query-ldflex/tree/test/45-performance now has a
So we can test things without a browser now. |
I can tell, and that is totally clear to me, even though you are right to say it, things are often better understood when said :-)
I'd be happy to dig into that, even though that won't help us here but I am totally up for catching that ball We reach back to you tomorrow regarding our progress towards a short term solution. |
|
In any case, we're definitely spending way too much time on SPARQL parsing (RubenVerborgh/SPARQL.js#94). It's a major contributor to time. |
This comment has been minimized.
This comment has been minimized.
|
I can confirm that the problem is in the browser-supplied version of |
|
And the root issue is likely this one: defunctzombie/node-process#86 |
|
When fixing Unfortunately, this performance does not translate directly to the browser. It seems that the browser build still contains code that executes differently on Node. So we need to dig deeper. Yet based on the above, I have already made some performance improvements. Please check out how this branch is working for you: https://github.com/solid/query-ldflex/tree/fix/browser-performance |
Instead of passing SPARQL queries to Comunica, LDflex could also just pass SPARQL algebra to Comunica directly. This would avoid the parsing overhead. (This is also how GraphQL-LD does it) |
|
Thanks Ruben for all this study. We're working on a workaround for now on our side. But it's a temporary measure, and as soon as we're done with it, we're gonna have to find a more definitive solution. |
|
Definitely, and we know where to look already. |
|
@sylvainlb @matthieu-fesselier @happy-dev |
|
I tested it and it works as expected. It does not make the first call faster, but the next ones are |
|
Thanks so much for testing this. Will close this now, while we follow up in Comunica to make queries as a whole faster in browsers. We now have several pointers to look at the performance differences. |
|
Thanks Ruben for all these efforts. We're still in the process of closing the crisis on our side, but I'll get back to you once we're done to see how we can proceed to integrate LDFlex in our work. Thanks! |
|
Hello @RubenVerborgh @rubensworks ! I follow up here as it seems to be the most appropriate issue related to performances. I investigated a bit more the performances with the last version of query-ldflex. (not sure all the dependencies were updated as they should be, maybe you can confirm?) Here is a real use case of an app made with Startin'blox. On load time:
I made some tests with LDFlex in replacement to our store. It does not loads all the resources mentioned above, it needed more work to make all the components work. However, here are some results:
Here is a small test I made with our data: <script src="solid-auth-client.bundle.js"></script>
<script src="solid-query-ldflex.bundle.js"></script>
<script>
document.addEventListener('DOMContentLoaded', async () => {
const data = solid.data['https://api.community.hubl.world/skills/'];
for await (const s of data['ldp:contains']) {
const id = s.value;
console.time(id)
await s['rdfs:label'].value;
await s['type'].value;
console.timeEnd(id)
}
});
</script>I tested with distant data (https://api.community.hubl.world/skills/) and the same data in a local jsonld file, with the same results. Each time shows between 15 and 20ms. As they are all executed sequentially, it takes around 12s to have the whole list loaded. I hope it helps, don't hesitate to reach back if you need more informations about our tests/uses cases! |
|
Thanks @matthieu-fesselier, this is a very interesting case, which we will analyze in detail. Quick thoughts:
|
|
Reminder to self: the above remarks pertain to this hack rather than the |
|
A more precise example which illustrates what I said before: <pre id="test"></pre>
<script>
// for freeze test
setInterval(() => {
document.getElementById('test').textContent = Math.random();
}, 200);
document.addEventListener('DOMContentLoaded', async () => {
const skills = 'https://api.community.hubl.world/skills/';
const context = {
'@vocab': 'http://happy-dev.fr/owl/#',
rdf: 'http://www.w3.org/1999/02/22-rdf-syntax-ns#',
rdfs: 'http://www.w3.org/2000/01/rdf-schema#',
ldp: 'http://www.w3.org/ns/ldp#',
foaf: 'http://xmlns.com/foaf/0.1/',
name: 'rdfs:label',
acl: 'http://www.w3.org/ns/auth/acl#',
permissions: 'acl:accessControl',
mode: 'acl:mode',
geo: "http://www.w3.org/2003/01/geo/wgs84_pos#",
lat: "geo:lat",
lng: "geo:long"
};
await solid.data.context.extend(context);
const data = solid.data[skills];
console.time('iteration')
for await (const s of data['http://www.w3.org/ns/ldp#contains']) { }
console.timeEnd('iteration')
console.time('iteration + value')
for await (const s of data['http://www.w3.org/ns/ldp#contains']) {
const id = s.value;
}
console.timeEnd('iteration + value')
console.time('iteration + 1 prop')
for await (const s of data['http://www.w3.org/ns/ldp#contains']) {
await s['rdfs:label'].value;
}
console.timeEnd('iteration + 1 prop')
console.time('iteration + 2 props')
for await (const s of data['http://www.w3.org/ns/ldp#contains']) {
await s['rdfs:label'].value;
await s['type'].value;
}
console.timeEnd('iteration + 2 props')
});
</script>With this, I can see that:
|
FYI we have this now here: RubenVerborgh/AsyncIterator@c0d8cac#diff-1a12957b96162e114d61ede68b100ab3R13-R21 |
|
Following up with the tests I made just above with the new version of AsyncIterator, I am facing a bug, which might be related to #71 . document.addEventListener('DOMContentLoaded', async () => {
const skills = 'https://api.community.hubl.world/skills/';
const data = solid.data[skills];
// 1rst loop
for await (const s of data['http://www.w3.org/ns/ldp#contains']) { }
console.log('passes here...');
// 2nd loop
for await (const s of data['http://www.w3.org/ns/ldp#contains']) {
console.log('but not here');
const id = s.value;
}
console.log('and here neither');
});Did I miss something? |
|
I suspect #71 indeed, we're investigating it. |
|
For reference, if it helps, I runned some additionnal tests based on the code I showed here, and here are the results:
(1) I used the |
I face performances issues when accessing datas on a container. It makes all our apps not useable for now with LDFlex. For example, with the following code:
It takes ~3000ms to display 70 times the
imgproperty of a resource.For each resource, it takes between 10ms to 90ms to display its
img.Is there something we can do to improve this?
The text was updated successfully, but these errors were encountered: