Teiid 8.4 performance degrading with multiple concurrent requests
anilallewar Feb 26, 2014 7:36 PMWe are trying to perform load testing against a VDB going to a SQL Server by generating 40 concurrent requests. The table has about 768075 rows and we are just trying to read the first 1000 (data about .5 MB) by sending concurrent read requests to Teiid using/eclipse-open:☂=DSDSClient/C:\/Program Files\/Java\/jre6\/lib\/rt.jar<java.util.concurrent(ExecutorService.class☃ExecutorServicejava.util.concurrent.ExecutorService by running Runnable workers.
What we observed is that the query response time increases linearly based on the number of requests with the first clocking around seconds to the 40th one clocking 219 seconds. I have tried moving the memory off the heap and specifying the buffer manager settings but that didn't improve the performance. If I instead use the SQL driver to go against the database directly by creating 1 connection per thread, all the 40 requests complete max by 2 seconds.
Here are the memory settings
"JAVA_OPTS=-Xms1024M -Xmx4096M -XX:MaxPermSize=512M -XX:MaxDirectMemorySize=8G"
and the Buffer manager settings
<buffer-service use-disk="true" processor-batch-size="256" memory-buffer-off-heap="true" />
The results from the test
The time taken to run the query for iteration [18] is [40] seconds The time taken to run the query for iteration [22] is [44] seconds The time taken to run the query for iteration [34] is [52] seconds The time taken to run the query for iteration [28] is [63] seconds The time taken to run the query for iteration [32] is [64] seconds The time taken to run the query for iteration [12] is [64] seconds The time taken to run the query for iteration [11] is [67] seconds The time taken to run the query for iteration [23] is [67] seconds The time taken to run the query for iteration [10] is [69] seconds The time taken to run the query for iteration [33] is [70] seconds The time taken to run the query for iteration [5] is [90] seconds The time taken to run the query for iteration [25] is [99] seconds The time taken to run the query for iteration [8] is [100] seconds The time taken to run the query for iteration [13] is [107] seconds The time taken to run the query for iteration [35] is [107] seconds The time taken to run the query for iteration [26] is [114] seconds The time taken to run the query for iteration [38] is [118] seconds The time taken to run the query for iteration [7] is [121] seconds The time taken to run the query for iteration [4] is [122] seconds The time taken to run the query for iteration [30] is [125] seconds The time taken to run the query for iteration [17] is [127] seconds The time taken to run the query for iteration [9] is [148] seconds The time taken to run the query for iteration [16] is [154] seconds The time taken to run the query for iteration [37] is [162] seconds The time taken to run the query for iteration [14] is [167] seconds The time taken to run the query for iteration [2] is [174] seconds The time taken to run the query for iteration [15] is [178] seconds The time taken to run the query for iteration [6] is [180] seconds The time taken to run the query for iteration [27] is [181] seconds The time taken to run the query for iteration [1] is [187] seconds The time taken to run the query for iteration [39] is [187] seconds The time taken to run the query for iteration [3] is [192] seconds The time taken to run the query for iteration [31] is [193] seconds The time taken to run the query for iteration [29] is [195] seconds The time taken to run the query for iteration [40] is [201] seconds The time taken to run the query for iteration [20] is [201] seconds The time taken to run the query for iteration [19] is [209] seconds The time taken to run the query for iteration [36] is [216] seconds The time taken to run the query for iteration [24] is [217] seconds The time taken to run the query for iteration [21] is [219] seconds
Snapshot of runtime resources used by Teiid
Metric | Actual |
Session Count: | 2 |
Memory in Use(KB): | 0 |
Memory Used By Active Plans(KB): | -28472 |
Buffer Disk Reads: | 640 |
Buffer Disk Writes: | 118920 |
Buffer Cache Reads: | 640 |
Buffer Cache Writes: | 119811 |
Disk Space In Use(MB): | 1336 |
Active Plan Count: | 1 |
Waiting Plan Count: | 0 |
What I noticed was that there were connection close exceptions on the server but the query ran fine.
16:38:29,424 ERROR [org.teiid.TRANSPORT] (New I/O worker #2) Unhandled exception , closing client instance: java.io.IOException: An existing connection was forci bly closed by the remote host
I also tried setting the buffer manager settings specifically as below.
<subsystem xmlns="urn:jboss:domain:teiid:1.0"> <async-thread-pool>teiid-async</async-thread-pool> <max-threads>150</max-threads> <max-active-plans>20</max-active-plans> <!-- 1. Set the buffer manager to use disk. 2. Reduce the processor-batch-size(number of records in a batch) processed by the teiid buffer manager from 512 to 256 3. Set the max-processing-kb (The approximate amount of buffer memory in kilobytes allowable for a single processing operation (sort, grouping, etc.) regardless of existing memory commitments) to be 2GB 4. Set the max-reserve-kb (The approximate amount of memory in kilobytes allowed to be held by the buffer manager) to be 4 GB 5. Set the max-storage-object-size(maximum size of a buffered managed object in bytes and represents the individual batch page size) to 64 MB (64*1024*1024) 6. Set the memory-buffer-space (Memory buffer space used by the buffer manager in MB) to be 6GB. Need to find out how this is different from max-reserve-kb 7. Set the memory-buffer-off-heap (Set to true to hold the memory buffer off-heap. If true you must ensure that the VM can allocate that much direct memory) to "true" --> <buffer-service use-disk="true" processor-batch-size="256" max-processing-kb="2097152" max-reserve-kb="4194304" max-storage-object-size="67108864" memory-buffer-space="6144" memory-buffer-off-heap="true" />
But that gave exceptions for the buffer manager of nature as below
org.teiid.jdbc.TeiidSQLException: Batch not found in storage 4537 at org.teiid.jdbc.TeiidSQLException.create(TeiidSQLException.java:135) at org.teiid.jdbc.TeiidSQLException.create(TeiidSQLException.java:71) at org.teiid.jdbc.StatementImpl.postReceiveResults(StatementImpl.java:667) at org.teiid.jdbc.StatementImpl.access$100(StatementImpl.java:63) at org.teiid.jdbc.StatementImpl$2.onCompletion(StatementImpl.java:516) at org.teiid.client.util.ResultsFuture.done(ResultsFuture.java:130) at org.teiid.client.util.ResultsFuture.access$200(ResultsFuture.java:37) at org.teiid.client.util.ResultsFuture$1.receiveResults(ResultsFuture.java:75) at org.teiid.net.socket.SocketServerInstanceImpl.receivedMessage(SocketServerInstanceImpl.java:235) at org.teiid.net.socket.SocketServerInstanceImpl.read(SocketServerInstanceImpl.java:271) at sun.reflect.GeneratedMethodAccessor29.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) at java.lang.reflect.Method.invoke(Unknown Source) at org.teiid.net.socket.SocketServerConnectionFactory$ShutdownHandler.invoke(SocketServerConnectionFactory.java:102) at $Proxy1.read(Unknown Source) at org.teiid.net.socket.SocketServerInstanceImpl$RemoteInvocationHandler$1.get(SocketServerInstanceImpl.java:370) at org.teiid.jdbc.StatementImpl.executeSql(StatementImpl.java:525) at org.teiid.jdbc.StatementImpl.executeSql(StatementImpl.java:393) at org.teiid.jdbc.StatementImpl.executeQuery(StatementImpl.java:327) at com.lgc.dsl.client.ppdmdefect.jdbc.ReadTeiidWithJDBCDriverWorker.readEntitiesFromPPDM(ReadTeiidWithJDBCDriverWorker.java:79) at com.lgc.dsl.client.ppdmdefect.jdbc.ReadTeiidWithJDBCDriverWorker.run(ReadTeiidWithJDBCDriverWorker.java:31) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source) at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) at java.lang.Thread.run(Unknown Source) Caused by: org.teiid.core.TeiidException: Batch not found in storage 4537 at org.teiid.client.ResultsMessage.setException(ResultsMessage.java:202) at org.teiid.dqp.internal.process.RequestWorkItem.sendError(RequestWorkItem.java:957) at org.teiid.dqp.internal.process.RequestWorkItem.close(RequestWorkItem.java:543) at org.teiid.dqp.internal.process.RequestWorkItem.process(RequestWorkItem.java:346) at org.teiid.dqp.internal.process.AbstractWorkItem.run(AbstractWorkItem.java:51) at org.teiid.dqp.internal.process.RequestWorkItem.run(RequestWorkItem.java:248) at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:269) at org.teiid.dqp.internal.process.ThreadReuseExecutor$RunnableWrapper.run(ThreadReuseExecutor.java:119) at org.teiid.dqp.internal.process.ThreadReuseExecutor$3.run(ThreadReuseExecutor.java:214) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:662) Caused by: java.lang.AssertionError: Batch not found in storage 4537 at org.teiid.common.buffer.impl.BufferManagerImpl$BatchManagerImpl.getBatch(BufferManagerImpl.java:309) at org.teiid.common.buffer.TupleBuffer.getBatch(TupleBuffer.java:289) at org.teiid.dqp.internal.process.RequestWorkItem.sendResultsIfNeeded(RequestWorkItem.java:803) at org.teiid.dqp.internal.process.RequestWorkItem.processMore(RequestWorkItem.java:462) at org.teiid.dqp.internal.process.RequestWorkItem.process(RequestWorkItem.java:320
Can you please provide us with some pointers as to what can be done to tune the application?