Attachment 927816 Details for Bug 1131007 – Server log after query

Server log after query

server.log (text/plain), 15.74 KB, created by Juraj Duráni on 2014-08-18 11:34:29 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Juraj Duráni

Created: 2014-08-18 11:34:29 UTC

Size: 15.74 KB

patch

obsolete

>11:45:14,793 DEBUG [org.teiid.TRANSPORT] (New I/O worker #2) processing message:MessageHolder: key=0 contents=[B@14a62325
>11:45:14,800 DEBUG [org.teiid.SECURITY] (New I/O worker #2) authenticateUser jdurani JDBC
>11:45:14,826 DEBUG [org.teiid.SECURITY] (New I/O worker #2) Logon successful for " jdurani "
>11:45:14,828 DEBUG [org.teiid.SECURITY] (New I/O worker #2) Logon successful, created session: sessionid=YIjVweuxq283; userName=jdurani@teiid-security; vdbName=QT_Ingres10_Push; vdbVersion=1; createdTime=Fri Aug 08 11:45:14 CEST 2014; applicationName=JDBC; clientHostName=localhost; clientHardwareAddress=null; IPAddress=127.0.0.1; securityDomain=teiid-security; lastPingTime=Fri Aug 08 11:45:14 CEST 2014
>11:45:14,831 DEBUG [org.teiid.TRANSPORT] (New I/O worker #2) send message: MessageHolder: key=0 contents=[B@4a8da092
>11:45:14,868 DEBUG [org.teiid.TRANSPORT] (New I/O worker #2) processing message:MessageHolder: key=1 contents=Invoke interface org.teiid.client.DQP.executeRequest
>11:45:14,877 DEBUG [org.teiid.COMMAND_LOG] (New I/O worker #2) 	START USER COMMAND:	startTime=2014-08-08 11:45:14.876	requestID=YIjVweuxq283.0	txID=null	sessionID=YIjVweuxq283	applicationName=JDBC	principal=jdurani@teiid-security	vdbName=QT_Ingres10_Push	vdbVersion=1	sql=SELECT ByteNum, ABS(ByteNum) AS ABSByteNum FROM BQT2.SmallB ORDER BY ByteNum
>11:45:14,878 DEBUG [org.teiid.PROCESSOR] (Worker0_QueryProcessorQueue0) Request Thread YIjVweuxq283.0 with state NEW
>11:45:14,879 DEBUG [org.teiid.PROCESSOR] (Worker0_QueryProcessorQueue0) YIjVweuxq283.0 Non-cachable command.
>11:45:14,879 DEBUG [org.teiid.PROCESSOR] (Worker0_QueryProcessorQueue0) YIjVweuxq283.0 executing prepared SELECT ByteNum, ABS(ByteNum) AS ABSByteNum FROM BQT2.SmallB ORDER BY ByteNum
>11:45:14,972 DEBUG [org.teiid.PROCESSOR] (Worker0_QueryProcessorQueue0) ProcessTree for YIjVweuxq283.0 AccessNode(0) output=[convert(Source.smallb.bytenum, byte), ABS(convert(convert(Source.smallb.bytenum, byte), integer)) AS ABSByteNum] SELECT convert(g_0.bytenum, byte) AS c_0, ABS(convert(convert(g_0.bytenum, byte), integer)) AS c_1 FROM Source.smallb AS g_0 ORDER BY c_0
>
>11:45:14,986 DEBUG [org.teiid.TXN_LOG] (Worker0_QueryProcessorQueue0) before getOrCreateTransactionContext:org.teiid.dqp.internal.process.TransactionServerImpl@230e6110(YIjVweuxq283)
>11:45:14,986 DEBUG [org.teiid.TXN_LOG] (Worker0_QueryProcessorQueue0) after getOrCreateTransactionContext : YIjVweuxq283 NONE ID:NONE
>11:45:14,993 DEBUG [org.teiid.BUFFER_MGR] (Worker0_QueryProcessorQueue0) Creating TupleBuffer: 0 [BQT2.SmallB.ByteNum, ABS(convert(BQT2.SmallB.ByteNum, integer)) AS ABSByteNum] [class java.lang.Byte, class java.lang.Integer] batch size 2048 of type PROCESSOR
>11:45:14,996 DEBUG [org.teiid.CONNECTOR] (Worker0_QueryProcessorQueue0) YIjVweuxq283.0.0.0 Create State
>11:45:15,009 DEBUG [org.teiid.BUFFER_MGR] (Worker0_QueryProcessorQueue0) YIjVweuxq283.0.0.0 Blocking on source query YIjVweuxq283.0.0.0
>11:45:15,010 DEBUG [org.teiid.BUFFER_MGR] (Worker0_QueryProcessorQueue0) YIjVweuxq283.0 Blocking on source request(s).
>11:45:15,009 DEBUG [org.teiid.PROCESSOR] (Worker1_QueryProcessorQueue1) Running task for parent thread Worker0_QueryProcessorQueue0
>11:45:15,010 DEBUG [org.teiid.PROCESSOR] (Worker0_QueryProcessorQueue0) Request Thread YIjVweuxq283.0 - processor blocked
>11:45:15,010 DEBUG [org.teiid.CONNECTOR] (Worker1_QueryProcessorQueue1) YIjVweuxq283.0.0.0 Processing NEW request: SELECT convert(g_0.bytenum, byte) AS c_0, ABS(convert(convert(g_0.bytenum, byte), integer)) AS c_1 FROM Source.smallb AS g_0 ORDER BY c_0
>11:45:15,010 DEBUG [org.jboss.jca.core.connectionmanager.pool.idle.IdleRemover] (Worker1_QueryProcessorQueue1) Register pool: SemaphoreArrayListManagedConnectionPool@3c8508fc[pool=ingres10DS] (interval=1800000)
>11:45:15,010 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (Worker1_QueryProcessorQueue1) ingres10DS: getConnection(null, WrappedConnectionRequestInfo@4210f76e[userName=bqt2]) [0/20]
>11:45:15,011 DEBUG [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (Worker1_QueryProcessorQueue1) Driver loaded and instance created:Actian Corporation - JDBC Driver
>11:45:17,602 INFO  [org.teiid.CONNECTOR] (Worker1_QueryProcessorQueue1) IngresExecutionFactory Commit=true;DatabaseProductName=INGRES;DatabaseProductVersion=II 10.1.0 (a64.win/125)GPL;DriverMajorVersion=4;DriverMajorVersion=1;DriverName=Actian Corporation - JDBC Driver;DriverVersion=4.1.4;IsolationLevel=8
>11:45:17,610 DEBUG [org.teiid.CONNECTOR] (Worker1_QueryProcessorQueue1) YIjVweuxq283.0.0.0 Obtained execution
>11:45:17,611 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue1) 	START DATA SRC COMMAND:	startTime=2014-08-08 11:45:17.611	requestID=YIjVweuxq283.0	sourceCommandID=0	executionID=0	txID=null	modelName=Source	translatorName=ingres	sessionID=YIjVweuxq283	principal=jdurani@teiid-security	sql=SELECT convert(g_0.bytenum, byte) AS c_0, ABS(convert(convert(g_0.bytenum, byte), integer)) AS c_1 FROM Source.smallb AS g_0 ORDER BY c_0
>11:45:17,620 DEBUG [org.teiid.CONNECTOR] (Worker1_QueryProcessorQueue1) Source-specific command: SELECT cast(g_0.bytenum AS tinyint) AS c_0, abs(cast(g_0.bytenum AS tinyint)) AS c_1 FROM smallb AS g_0 ORDER BY c_0
>11:45:18,528 DEBUG [org.teiid.COMMAND_LOG] (Worker1_QueryProcessorQueue1) 	ERROR SRC COMMAND:	endTime=2014-08-08 11:45:18.528	requestID=YIjVweuxq283.0	sourceCommandID=0	executionID=0	txID=null	modelName=Source	translatorName=ingres	sessionID=YIjVweuxq283	principal=jdurani@teiid-security	finalRowCount=null
>11:45:18,529 WARN  [org.teiid.CONNECTOR] (Worker1_QueryProcessorQueue1) Connector worker process failed for atomic-request=YIjVweuxq283.0.0.0: org.teiid.translator.jdbc.JDBCExecutionException: 4200 TEIID11008:TEIID11004 Error executing statement(s): [Prepared Values: [] SQL: SELECT cast(g_0.bytenum AS tinyint) AS c_0, abs(cast(g_0.bytenum AS tinyint)) AS c_1 FROM smallb AS g_0 ORDER BY c_0]
>	at org.teiid.translator.jdbc.JDBCQueryExecution.execute(JDBCQueryExecution.java:131)
>	at org.teiid.dqp.internal.datamgr.ConnectorWorkItem.execute(ConnectorWorkItem.java:325) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.DataTierTupleSource.getResults(DataTierTupleSource.java:298) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.DataTierTupleSource$1.call(DataTierTupleSource.java:110) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.DataTierTupleSource$1.call(DataTierTupleSource.java:107) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_60]
>	at org.teiid.dqp.internal.process.FutureWork.run(FutureWork.java:58) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:274) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.ThreadReuseExecutor$RunnableWrapper.run(ThreadReuseExecutor.java:119) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.ThreadReuseExecutor$3.run(ThreadReuseExecutor.java:214) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_60]
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_60]
>	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_60]
>Caused by: java.sql.SQLDataException: Integer overflow detected in query.
>	at com.ingres.gcf.util.SqlExType.getSqlEx(SqlExType.java:103)
>	at com.ingres.gcf.util.SqlExFactory.get(SqlExFactory.java:96)
>	at com.ingres.gcf.jdbc.DrvObj.readError(DrvObj.java:852)
>	at com.ingres.gcf.jdbc.DrvObj.readResults(DrvObj.java:636)
>	at com.ingres.gcf.jdbc.RsltFtch.preLoad(RsltFtch.java:611)
>	at com.ingres.gcf.jdbc.RsltCurs.preLoad(RsltCurs.java:306)
>	at com.ingres.gcf.jdbc.RsltCurs.<init>(RsltCurs.java:235)
>	at com.ingres.gcf.jdbc.JdbcPrep.exec(JdbcPrep.java:1279)
>	at com.ingres.gcf.jdbc.JdbcPrep.executeQuery(JdbcPrep.java:589)
>	at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:462)
>	at org.teiid.translator.jdbc.JDBCQueryExecution.execute(JDBCQueryExecution.java:123)
>	... 12 more
>
>11:45:18,535 DEBUG [org.teiid.PROCESSOR] (Worker0_QueryProcessorQueue2) Request Thread YIjVweuxq283.0 with state PROCESSING
>11:45:18,536 DEBUG [org.teiid.CONNECTOR] (Worker0_QueryProcessorQueue2) YIjVweuxq283.0.0.0 Remove State
>11:45:18,536 DEBUG [org.teiid.CONNECTOR] (Worker0_QueryProcessorQueue2) YIjVweuxq283.0.0.0 Processing Close : SELECT convert(g_0.bytenum, byte) AS c_0, ABS(convert(convert(g_0.bytenum, byte), integer)) AS c_1 FROM Source.smallb AS g_0 ORDER BY c_0
>11:45:18,536 DEBUG [org.teiid.CONNECTOR] (Worker0_QueryProcessorQueue2) YIjVweuxq283.0.0.0 Closed execution
>11:45:18,537 DEBUG [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (Worker0_QueryProcessorQueue2) ingres10DS: returnConnection(4ede125b, false) [0/20]
>11:45:18,537 DEBUG [org.teiid.CONNECTOR] (Worker0_QueryProcessorQueue2) YIjVweuxq283.0.0.0 Closed connection
>11:45:18,537 DEBUG [org.teiid.PROCESSOR] (Worker0_QueryProcessorQueue2) QueryProcessor: closing processor
>11:45:18,537 DEBUG [org.teiid.COMMAND_LOG] (Worker0_QueryProcessorQueue2) 	ERROR USER COMMAND:	endTime=2014-08-08 11:45:18.537	requestID=YIjVweuxq283.0	txID=null	sessionID=YIjVweuxq283	principal=jdurani@teiid-security	vdbName=QT_Ingres10_Push	vdbVersion=1	finalRowCount=null
>11:45:18,538 WARN  [org.teiid.PROCESSOR] (Worker0_QueryProcessorQueue2) TEIID30020 Processing exception for request YIjVweuxq283.0 'TEIID30504 Source: 4200 TEIID11008:TEIID11004 Error executing statement(s): [Prepared Values: [] SQL: SELECT cast(g_0.bytenum AS tinyint) AS c_0, abs(cast(g_0.bytenum AS tinyint)) AS c_1 FROM smallb AS g_0 ORDER BY c_0]'. Originally TeiidProcessingException 'Integer overflow detected in query.' SqlExType.java:103.: org.teiid.core.TeiidProcessingException: TEIID30504 Source: 4200 TEIID11008:TEIID11004 Error executing statement(s): [Prepared Values: [] SQL: SELECT cast(g_0.bytenum AS tinyint) AS c_0, abs(cast(g_0.bytenum AS tinyint)) AS c_1 FROM smallb AS g_0 ORDER BY c_0]
>	at org.teiid.dqp.internal.process.DataTierTupleSource.exceptionOccurred(DataTierTupleSource.java:381) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.DataTierTupleSource.nextTuple(DataTierTupleSource.java:154) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.query.processor.relational.AccessNode.nextBatchDirect(AccessNode.java:369) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.query.processor.relational.RelationalNode.nextBatch(RelationalNode.java:278) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.query.processor.relational.RelationalPlan.nextBatch(RelationalPlan.java:136) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.query.processor.QueryProcessor.nextBatchDirect(QueryProcessor.java:151) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.query.processor.QueryProcessor.nextBatch(QueryProcessor.java:114) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.query.processor.BatchCollector.collectTuples(BatchCollector.java:159) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.query.processor.BatchCollector.collectTuples(BatchCollector.java:141) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.RequestWorkItem.processMore(RequestWorkItem.java:444) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.RequestWorkItem.process(RequestWorkItem.java:326) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.AbstractWorkItem.run(AbstractWorkItem.java:51) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.RequestWorkItem.run(RequestWorkItem.java:254) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.DQPWorkContext.runInContext(DQPWorkContext.java:274) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.ThreadReuseExecutor$RunnableWrapper.run(ThreadReuseExecutor.java:119) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.ThreadReuseExecutor$3.run(ThreadReuseExecutor.java:214) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [rt.jar:1.7.0_60]
>	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [rt.jar:1.7.0_60]
>	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_60]
>Caused by: org.teiid.translator.jdbc.JDBCExecutionException: 4200 TEIID11008:TEIID11004 Error executing statement(s): [Prepared Values: [] SQL: SELECT cast(g_0.bytenum AS tinyint) AS c_0, abs(cast(g_0.bytenum AS tinyint)) AS c_1 FROM smallb AS g_0 ORDER BY c_0]
>	at org.teiid.translator.jdbc.JDBCQueryExecution.execute(JDBCQueryExecution.java:131)
>	at org.teiid.dqp.internal.datamgr.ConnectorWorkItem.execute(ConnectorWorkItem.java:325) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.DataTierTupleSource.getResults(DataTierTupleSource.java:298) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.DataTierTupleSource$1.call(DataTierTupleSource.java:110) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at org.teiid.dqp.internal.process.DataTierTupleSource$1.call(DataTierTupleSource.java:107) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	at java.util.concurrent.FutureTask.run(FutureTask.java:262) [rt.jar:1.7.0_60]
>	at org.teiid.dqp.internal.process.FutureWork.run(FutureWork.java:58) [teiid-engine-8.7.1.redhat-1.jar:8.7.1.redhat-1]
>	... 6 more
>Caused by: java.sql.SQLDataException: Integer overflow detected in query.
>	at com.ingres.gcf.util.SqlExType.getSqlEx(SqlExType.java:103)
>	at com.ingres.gcf.util.SqlExFactory.get(SqlExFactory.java:96)
>	at com.ingres.gcf.jdbc.DrvObj.readError(DrvObj.java:852)
>	at com.ingres.gcf.jdbc.DrvObj.readResults(DrvObj.java:636)
>	at com.ingres.gcf.jdbc.RsltFtch.preLoad(RsltFtch.java:611)
>	at com.ingres.gcf.jdbc.RsltCurs.preLoad(RsltCurs.java:306)
>	at com.ingres.gcf.jdbc.RsltCurs.<init>(RsltCurs.java:235)
>	at com.ingres.gcf.jdbc.JdbcPrep.exec(JdbcPrep.java:1279)
>	at com.ingres.gcf.jdbc.JdbcPrep.executeQuery(JdbcPrep.java:589)
>	at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:462)
>	at org.teiid.translator.jdbc.JDBCQueryExecution.execute(JDBCQueryExecution.java:123)
>	... 12 more
>
>11:45:18,542 DEBUG [org.teiid.PROCESSOR] (Worker0_QueryProcessorQueue2) Removing tuplesource for the request YIjVweuxq283.0
>11:45:18,542 DEBUG [org.teiid.BUFFER_MGR] (Worker0_QueryProcessorQueue2) Removing TupleBuffer: 0
>11:45:18,542 DEBUG [org.teiid.PROCESSOR] (Worker0_QueryProcessorQueue2) org.teiid.core.TeiidProcessingException: TEIID30504 Source: 4200 TEIID11008:TEIID11004 Error executing statement(s): [Prepared Values: [] SQL: SELECT cast(g_0.bytenum AS tinyint) AS c_0, abs(cast(g_0.bytenum AS tinyint)) AS c_1 FROM smallb AS g_0 ORDER BY c_0] Sending error to client YIjVweuxq283.0
>11:45:18,543 DEBUG [org.teiid.TRANSPORT] (Worker0_QueryProcessorQueue2) send message: MessageHolder: key=1 contents=ResultsMessage rowCount=0 finalRow=-1
>11:45:18,598 DEBUG [org.teiid.TRANSPORT] (New I/O worker #2) processing message:MessageHolder: key=2 contents=Invoke interface org.teiid.client.security.ILogon.logoff
>11:45:18,598 DEBUG [org.teiid.SECURITY] (New I/O worker #2) closeSession YIjVweuxq283
>11:45:18,598 DEBUG [org.teiid.TXN_LOG] (New I/O worker #2) before cancelTransactions:org.teiid.dqp.internal.process.TransactionServerImpl@230e6110(YIjVweuxq283,false)
>11:45:18,599 DEBUG [org.teiid.TXN_LOG] (New I/O worker #2) after cancelTransactions : null
>11:45:18,599 DEBUG [org.teiid.TRANSPORT] (New I/O worker #2) send message: MessageHolder: key=2 contents=null
>11:45:18,608 DEBUG [org.teiid.TRANSPORT] (New I/O worker #2) Channel closed

Actions: View

Attachments on bug 1131007: 927814 | 927815 | 927816