Throughput Issues

Wednesday, 11 December 2013 · 7 messages · last reply 12 Dec 2013
JM
Jeremy Moseley11 Dec 2013 00:11 #
Hi Guys, I am attempting to diagnose some throughput issues we are having with BaseX, and I was hoping to get some input on a couple of thread blocking issues I am noticing. Please see the Gist ( https://gist.github.com/jerezzprime/7901172) containing the thread dumps for reference. These thread dumps were generated while BaseX was handling a large number of requests produced using Apache Benchmark. All requests were being made against the same URL and the thread dumps were gathered over a 30 second period. The most common place for threads to be blocking is at org.basex.io.random.TableDiskAccess.read*. The threads are waiting for other threads to finish, since these method calls are synchronized. Is it possible to concurrently read from disk? Another place threads appear to be blocking is while waiting for the lock to call org.basex.http.RestXqModules.cache (another synchronized method). It seems like this should only be called once to parse the modules, and then all requests afterwards should be retrieved from the cache, but from the thread dumps it appears threads are still re-parsing the xquery modules. Is this expected behavior? Thanks, Jeremy
CG
Christian Grün11 Dec 2013 18:21 #
Hi Jeremy,
Quoted text · Jeremy Moseley · 4 lines
> The most common place for threads to be blocking is at > org.basex.io.random.TableDiskAccess.read*. The threads are waiting for other > threads to finish, since these method calls are synchronized. Is it possible > to concurrently read from disk?
Concurrent reads are indeed supported, but the most lower-level operations need to be synchronized in order to avoid two operations changing the file offset pointer at the same time. It’s interesting to hear that this could be a potential bottleneck for your use case, as it hasn’t been of importance in our benchmarks and profilings so far.
Quoted text · Jeremy Moseley · 6 lines
> Another place threads appear to be blocking is while waiting for the lock to > call org.basex.http.RestXqModules.cache (another synchronized method). It > seems like this should only be called once to parse the modules, and then > all requests afterwards should be retrieved from the cache, but from the > thread dumps it appears threads are still re-parsing the xquery modules. Is > this expected behavior?
With each RESTXQ call, the restxq directory will be parsed for changes. If XQuery Modules are modified or added, they will be parsed before the actual request is answered. – Usually, this check shouldn’t represent any bottleneck, but we could think about an option that disallows changes to the RESTXQ directory while the server is running. – Do you have many files in your RESTXQ directory? Hope this helps, Christian
JM
Jeremy Moseley11 Dec 2013 21:36 #
Hey Christian, Your response makes me think that perhaps the locking is not the bottle neck, and I am simply catching the threads at the wrong times, but the fact that the majority of them are blocked makes me think this may be a bigger issue. No files in the RESTXQ folder are changing at runtime, and from looking at the code it appears that the result of the parsing should be cached unless the files change anyways, but that does not appear to be the case, at least from my analysis of the thread dumps. Could this possibly be a bug? Should I be getting better throughput than 0.5 - 10 requests per second? Generally it is 0.5 - 3 requests per second for standard size projects (6000+ XML files), where we are performing queries for nodes by attribute index, and faster 10 - 15 requests per second for smaller projects, same type of queries. Can you think of a way to speed this up, perhaps moving the Table files directly into memory, to minimize disk accesses? Thanks, Jeremy
Quoted text · Christian Grün · 35 lines
On Dec 11, 2013 9:21 AM, "Christian Grün" <christian.gruen at gmail.com> wrote: > Hi Jeremy, > > > The most common place for threads to be blocking is at > > org.basex.io.random.TableDiskAccess.read*. The threads are waiting for > other > > threads to finish, since these method calls are synchronized. Is it > possible > > to concurrently read from disk? > > Concurrent reads are indeed supported, but the most lower-level > operations need to be synchronized in order to avoid two operations > changing the file offset pointer at the same time. It’s interesting to > hear that this could be a potential bottleneck for your use case, as > it hasn’t been of importance in our benchmarks and profilings so far. > > > Another place threads appear to be blocking is while waiting for the > lock to > > call org.basex.http.RestXqModules.cache (another synchronized method). It > > seems like this should only be called once to parse the modules, and then > > all requests afterwards should be retrieved from the cache, but from the > > thread dumps it appears threads are still re-parsing the xquery modules. > Is > > this expected behavior? > > With each RESTXQ call, the restxq directory will be parsed for > changes. If XQuery Modules are modified or added, they will be parsed > before the actual request is answered. – Usually, this check shouldn’t > represent any bottleneck, but we could think about an option that > disallows changes to the RESTXQ directory while the server is running. > – Do you have many files in your RESTXQ directory? > > Hope this helps, > Christian >
CG
Christian Grün12 Dec 2013 21:33 #
Quoted text · Jeremy Moseley · 4 lines
> No files in the RESTXQ folder are changing at runtime, and from looking at > the code it appears that the result of the parsing should be cached unless > the files change anyways, but that does not appear to be the case, at least > from my analysis of the thread dumps. Could this possibly be a bug?
I may need to have another look into your dumps, but maybe you can tell me faster what you think is happening here, and why you think it’s a bug?
Quoted text · Jeremy Moseley · 6 lines
> Should I be getting better throughput than 0.5 - 10 requests per second? > Generally it is 0.5 - 3 requests per second for standard size projects > (6000+ XML files), where we are performing queries for nodes by attribute > index, and faster 10 - 15 requests per second for smaller projects, same > type of queries. Can you think of a way to speed this up, perhaps moving the > Table files directly into memory, to minimize disk accesses?
So you say that one query takes a maximum ~0.5 seconds to be evaluated. Synchronization shouldn’t be a problem when all calls are run sequentially, so I would be interested what performance you get when you run all queries sequentially? Regarding the queries: I guess I asked before, but maybe there’s a chance to speed up single queries? How do your queries look like? Christian
CG
Christian Grünin reply to Jeremy Moseley, 12 Dec 2013, 22:5012 Dec 2013 22:08 #
Quoted text · Jeremy Moseley · 4 lines
> It looks like a bug simply because it seems like all (perhaps only some?) > threads are reparsing the RESTXQ files, even when the modified time has not > changed, and other threads are blocked on the cache object that holds the > results of the parse.
Your feedback is welcome if you should decide to go deeper into that issue (I didn’t spend much time yet, but I couldn’t confirm this so far in my tests).
Quoted text · Jeremy Moseley · 3 lines
> When I run the query by itself, average time is anywhere from 300 ms - 800 > ms, but when I run concurrently, things slow way down. Below is the > percentile speeds output by Apache Benchmark:
300 ms-800 ms doesn’t sound that exciting; maybe we’d have some potential here to speed up things up. Have you done some profiling of single queries, too (either on XQuery or Java level), even if single queries turn out to be fast enough for you?
JM
Jeremy Moseleyin reply to Christian Grün, 12 Dec 2013, 21:3312 Dec 2013 22:50 #
Hey Christian, It looks like a bug simply because it seems like all (perhaps only some?) threads are reparsing the RESTXQ files, even when the modified time has not changed, and other threads are blocked on the cache object that holds the results of the parse. When I run the query by itself, average time is anywhere from 300 ms - 800 ms, but when I run concurrently, things slow way down. Below is the percentile speeds output by Apache Benchmark:
Quoted text · Christian Grün · 9 lines
> 0% 9316 > 66% 10805 > 75% 11372 > 80% 11835 > 90% 13794 > 95% 15221 > 98% 16051 > 99% 16130 > 100% 16130 (longest request)
and this is the output from $ time curl "localhost:8984/xmldb/request" > /dev/null % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 112 448 112 448 0 0 802 0 --:--:-- --:--:-- --:--:-- 802 real 0m0.567s user 0m0.010s sys 0m0.000s Both Apache Benchmark, and the curl command are requesting the same URL. The queries themselves involve looping over all href nodes in the documents, using the db:attribute function to lookup other nodes based on the value of this, and then formatting the information into JSON, and output to the client. I believe the queries are as fast as they are going to be, and a single query runs fast enough for our needs. Any thoughts?
Quoted text · Christian Grün · 32 lines
On Dec 12, 2013 12:33 PM, "Christian Grün" <christian.gruen at gmail.com> wrote: > > No files in the RESTXQ folder are changing at runtime, and from looking > at > > the code it appears that the result of the parsing should be cached > unless > > the files change anyways, but that does not appear to be the case, at > least > > from my analysis of the thread dumps. Could this possibly be a bug? > > I may need to have another look into your dumps, but maybe you can > tell me faster what you think is happening here, and why you think > it’s a bug? > > > Should I be getting better throughput than 0.5 - 10 requests per second? > > Generally it is 0.5 - 3 requests per second for standard size projects > > (6000+ XML files), where we are performing queries for nodes by attribute > > index, and faster 10 - 15 requests per second for smaller projects, same > > type of queries. Can you think of a way to speed this up, perhaps moving > the > > Table files directly into memory, to minimize disk accesses? > > So you say that one query takes a maximum ~0.5 seconds to be > evaluated. Synchronization shouldn’t be a problem when all calls are > run sequentially, so I would be interested what performance you get > when you run all queries sequentially? > > Regarding the queries: I guess I asked before, but maybe there’s a > chance to speed up single queries? How do your queries look like? > > Christian >
JM
Jeremy Moseley12 Dec 2013 23:16 #
Hey Christian, To follow up about why I think it may be a bug, if you look at the org.basex.http.RestXQModules class, it seems like many threads are blocking in the cache method, which is synchronized, while a thread is busy reparsing the files, though none of them changed. It makes sense that these results should be cached, I just can't imagine why the reparsing is happening more than once, even if the files haven't changed. The thread dumps show several threads blocked in the cache method, and the thread holding the lock is busy parsing the files. Sorry for not being a bit clearer in my previous response, Jeremy
Quoted text · Jeremy Moseley · 82 lines
On Thu, Dec 12, 2013 at 12:50 PM, Jeremy Moseley <jeremy at inkling.com> wrote: > Hey Christian, > > It looks like a bug simply because it seems like all (perhaps only some?) > threads are reparsing the RESTXQ files, even when the modified time has not > changed, and other threads are blocked on the cache object that holds the > results of the parse. > > When I run the query by itself, average time is anywhere from 300 ms - 800 > ms, but when I run concurrently, things slow way down. Below is the > percentile speeds output by Apache Benchmark: > >> 0% 9316 >> 66% 10805 >> 75% 11372 >> 80% 11835 >> 90% 13794 >> 95% 15221 >> 98% 16051 >> 99% 16130 >> 100% 16130 (longest request) > > > and this is the output from $ time curl "localhost:8984/xmldb/request" > > /dev/null > > % Total % Received % Xferd Average Speed Time Time Time > Current > Dload Upload Total Spent Left > Speed > 112 448 112 448 0 0 802 0 --:--:-- --:--:-- --:--:-- > 802 > > real 0m0.567s > user 0m0.010s > sys 0m0.000s > > Both Apache Benchmark, and the curl command are requesting the same URL. > > The queries themselves involve looping over all href nodes in the > documents, using the db:attribute function to lookup other nodes based on > the value of this, and then formatting the information into JSON, and > output to the client. I believe the queries are as fast as they are going > to be, and a single query runs fast enough for our needs. > > Any thoughts? > > On Dec 12, 2013 12:33 PM, "Christian Grün" <christian.gruen at gmail.com> > wrote: > >> > No files in the RESTXQ folder are changing at runtime, and from looking >> at >> > the code it appears that the result of the parsing should be cached >> unless >> > the files change anyways, but that does not appear to be the case, at >> least >> > from my analysis of the thread dumps. Could this possibly be a bug? >> >> I may need to have another look into your dumps, but maybe you can >> tell me faster what you think is happening here, and why you think >> it’s a bug? >> >> > Should I be getting better throughput than 0.5 - 10 requests per second? >> > Generally it is 0.5 - 3 requests per second for standard size projects >> > (6000+ XML files), where we are performing queries for nodes by >> attribute >> > index, and faster 10 - 15 requests per second for smaller projects, same >> > type of queries. Can you think of a way to speed this up, perhaps >> moving the >> > Table files directly into memory, to minimize disk accesses? >> >> So you say that one query takes a maximum ~0.5 seconds to be >> evaluated. Synchronization shouldn’t be a problem when all calls are >> run sequentially, so I would be interested what performance you get >> when you run all queries sequentially? >> >> Regarding the queries: I guess I asked before, but maybe there’s a >> chance to speed up single queries? How do your queries look like? >> >> Christian >> >

⚡Generated with XQuery