Data read scenario failing after Teiid version upgrade

[pranavk]

Hi,

I was using Teiid 9.2.1 earlier and upgraded to 11.1.1 in my application which is using Teiid embedded. The same data reads scenario which were running fine earlier have started giving me exceptions and failing. I haven't changed anything else, but just the Teiid version in pom files. The use case in question here is reading from MSSQL server database from a table having around 5 million rows and 20 columns. The read was failing after exactly a constant number of records each time. Same was the case when I tried to read heavy data from other sources.

I was able to get around some of these by increasing the fetch size on Teiid embedded connection from 100 previously to 1000. But I just want to understand whether there is conscious change in the way this operates now or is there something else that I am missing?

Thanks,

Pranav

Exception logs:

ERROR PROCESSOR TEIID30019 Unexpected exception for request hk63HpbFmzje.10

org.teiid.core.TeiidComponentException: TEIID31261 Max estimated size 1,228,691,277 for a single operation/table id 202 has been exceeded.  The server may need to increase the amount of disk or memory available, or decrease

        at org.teiid.common.buffer.impl.BufferManagerImpl$BatchManagerImpl.updateEstimates(BufferManagerImpl.java:300)

        at org.teiid.common.buffer.impl.BufferManagerImpl$BatchManagerImpl.createManagedBatch(BufferManagerImpl.java:275)

        at org.teiid.common.buffer.TupleBuffer.saveBatch(TupleBuffer.java:246)

        at org.teiid.common.buffer.TupleBuffer.addTuple(TupleBuffer.java:179)

        at org.teiid.common.buffer.TupleBuffer.addTupleBatch(TupleBuffer.java:193)

        at org.teiid.query.processor.BatchCollector.flushBatchDirect(BatchCollector.java:226)

        at org.teiid.dqp.internal.process.RequestWorkItem$1.flushBatchDirect(RequestWorkItem.java:710)

        at org.teiid.query.processor.BatchCollector.flushBatch(BatchCollector.java:220)

        at org.teiid.query.processor.BatchCollector.collectTuples(BatchCollector.java:191)

        at org.teiid.query.processor.BatchCollector.collectTuples(BatchCollector.java:142)

        at org.teiid.dqp.internal.process.RequestWorkItem.processMore(RequestWorkItem.java:492)

        at org.teiid.dqp.internal.process.RequestWorkItem.process(RequestWorkItem.java:362)

        at org.teiid.dqp.internal.process.AbstractWorkItem.run(AbstractWorkItem.java:47)

        at org.teiid.dqp.internal.process.RequestWorkItem.run(RequestWorkItem.java:285)

        at org.teiid.dqp.internal.process.RequestWorkItem.doMoreWork(RequestWorkItem.java:341)

        at org.teiid.dqp.internal.process.RequestWorkItem.requestMore(RequestWorkItem.java:1275)

        at org.teiid.dqp.internal.process.DQPCore.processCursorRequest(DQPCore.java:359)

        at sun.reflect.GeneratedMethodAccessor706.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

        at java.lang.reflect.Method.invoke(Method.java:498)

        at org.teiid.logging.LogManager$LoggingProxy.invoke(LogManager.java:117)

        at org.teiid.transport.SessionCheckingProxy.invoke(SessionCheckingProxy.java:60)

        at com.sun.proxy.$Proxy253.processCursorRequest(Unknown Source)

        at sun.reflect.GeneratedMethodAccessor706.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

        at java.lang.reflect.Method.invoke(Method.java:498)

        at org.teiid.transport.LocalServerConnection$1$1.call(LocalServerConnection.java:213)

        at java.util.concurrent.FutureTask.run(FutureTask.java:266)

        at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:277)

        at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:261)

        at org.teiid.transport.LocalServerConnection$1.invoke(LocalServerConnection.java:211)

        at com.sun.proxy.$Proxy253.processCursorRequest(Unknown Source)

        at org.teiid.jdbc.ResultSetImpl.submitRequestBatch(ResultSetImpl.java:420)

        at org.teiid.jdbc.ResultSetImpl.requestBatch(ResultSetImpl.java:383)

        at org.teiid.jdbc.BatchResults.requestBatchAndWait(BatchResults.java:223)

        at org.teiid.jdbc.BatchResults.requestNextBatch(BatchResults.java:138)

        at org.teiid.jdbc.BatchResults.hasNext(BatchResults.java:249)

        at org.teiid.jdbc.ResultSetImpl.hasNext(ResultSetImpl.java:506)

        at org.teiid.jdbc.ResultSetImpl.next(ResultSetImpl.java:255)

        at org.apache.commons.dbcp.DelegatingResultSet.next(DelegatingResultSet.java:207)

        at org.apache.commons.dbcp.DelegatingResultSet.next(DelegatingResultSet.java:207)

Caused by: org.teiid.jdbc.TeiidSQLException: TEIID30495 The request hk63HpbFmzje.10 has been closed.

        at org.teiid.jdbc.TeiidSQLException.create(TeiidSQLException.java:131)

        at org.teiid.jdbc.TeiidSQLException.create(TeiidSQLException.java:67)

        at org.teiid.jdbc.ResultSetImpl.submitRequestBatch(ResultSetImpl.java:422)

        at org.teiid.jdbc.ResultSetImpl.requestBatch(ResultSetImpl.java:383)

        at org.teiid.jdbc.BatchResults.requestBatchAndWait(BatchResults.java:223)

        at org.teiid.jdbc.BatchResults.requestNextBatch(BatchResults.java:138)

        at org.teiid.jdbc.BatchResults.hasNext(BatchResults.java:249)

        at org.teiid.jdbc.ResultSetImpl.hasNext(ResultSetImpl.java:506)

        at org.teiid.jdbc.ResultSetImpl.next(ResultSetImpl.java:255)

        at org.apache.commons.dbcp.DelegatingResultSet.next(DelegatingResultSet.java:207)

        at org.apache.commons.dbcp.DelegatingResultSet.next(DelegatingResultSet.java:207)

        at com.pb.spectrum.edi.jdbc.runtime.AbstractJdbcDataSourceReader.read(AbstractJdbcDataSourceReader.java:298)

        ... 9 more

Caused by: org.teiid.core.TeiidProcessingException: TEIID30495 The request hk63HpbFmzje.10 has been closed.

        at org.teiid.dqp.internal.process.DQPCore.getRequestWorkItem(DQPCore.java:479)

        at org.teiid.dqp.internal.process.DQPCore.processCursorRequest(DQPCore.java:358)

        at sun.reflect.GeneratedMethodAccessor706.invoke(Unknown Source)

       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

        at java.lang.reflect.Method.invoke(Method.java:498)

        at org.teiid.logging.LogManager$LoggingProxy.invoke(LogManager.java:117)

        at org.teiid.transport.SessionCheckingProxy.invoke(SessionCheckingProxy.java:60)

        at com.sun.proxy.$Proxy253.processCursorRequest(Unknown Source)

        at sun.reflect.GeneratedMethodAccessor706.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

        at java.lang.reflect.Method.invoke(Method.java:498)

        at org.teiid.transport.LocalServerConnection$1$1.call(LocalServerConnection.java:213)

        at java.util.concurrent.FutureTask.run(FutureTask.java:266)

        at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:277)

        at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:261)

        at org.teiid.transport.LocalServerConnection$1.invoke(LocalServerConnection.java:211)

        at com.sun.proxy.$Proxy253.processCursorRequest(Unknown Source)

        at org.teiid.jdbc.ResultSetImpl.submitRequestBatch(ResultSetImpl.java:420)

        ... 18 more

[shawkins]

> But I just want to understand whether there is conscious change in the way this operates now or is there something else that I am missing?

Yes this was from [TEIID-4557] Enable memory management at the query level - JBoss Issue Tracker  and [TEIID-2465] Add additional size limitations - JBoss Issue Tracker to add in some defaults around preventing run away resource consumption.  If you were predominately using Teiid in a low query volume manner, the defaults, especially for max active plans (20), are now causing the exception to be thrown.  If you need these restrictions to be an optional feature, or to make some of the other setting more adaptive, please log an issue.

[rareddy]

Steve,

Is there a way to manage this limit? Also reducing the active plans might also help correct?

Ramesh..

[shawkins]

> Is there a way to manage this limit? Also reducing the active plans might also help correct?

To turn it off entirely no.  Max active plans and memory / disk are mentioned in the exception message.

[rareddy]

I mean any property like "maxQueryMemoryLimit" that overrides the above limit? The message got cut off above, so I missed that about exception

[shawkins]

No there is no additional setting currently.  It's all derived from the other primary properties.

[pranavk]

Thanks for the clarification Steve and Ramesh. In my opinion, since a default config/behavior that I had been using since many version just started breaking one version onwards, I feel there should be a way to turn this overrun prevention mechanism off (or optional).

One question on this - all the data reads that were failing on different tables due to this stop failing if I increase the JDBC connection fetch size from 100 (which is the default for my application) to 1000. Why/how is this affected by the top level fetch size?

Also, @Ramesh, reducing the active plans didn't really help much in most cases in my test scenario.

[shawkins]

> I feel there should be a way to turn this overrun prevention mechanism off (or optional)

Please log an issue for that, and we'll get it addressed.

Ideally finding failing scenarios would help identify where:

- the configuration could be adjusted, which you already did for max plans, but it didn't have enough effect

- the heap memory estimation is too large.

- situations where clients were requesting scrolling over large results that may not needed

Ideally we could learn more about the potential over-estimation of heap usage in this case.  What are the columns/types of the user query?  About how wide is the data in each row, how many rows are being returned?  Does it seem that the client is lagging behind the server production of batches?

Even with the exception turned off, we'll leave a warning so that the scenario could still be analyzed.

> One question on this - all the data reads that were failing on different tables due to this stop failing if I increase the JDBC connection fetch size from 100 (which is the default for my application) to 1000. Why/how is this affected by the top level fetch size?

From the stack above you are receiving the exception on the output buffer of processing, presumably with a larger fetch size you are drawing that down faster.  If you don't see memory issues on the client side, it may be good to use the larger fetch size in general.

[shawkins]

There will be two related changes with [TEIID-5525] add a flag to revert to the prior behavior (TEIID-4557) - JBoss Issue Tracker

A flag will be introduced to change the exception into a warning.  Also the default formula will be adjusted to better account for the size difference between heap based and serialized batches.