Bug 1323721 - Command DB Logging - SQLCMD attribute VARCHAR(8196) is too small for large queries
Summary: Command DB Logging - SQLCMD attribute VARCHAR(8196) is too small for large qu...
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: JBoss Data Virtualization 6
Classification: JBoss
Component: Teiid
Version: 6.2.0
Hardware: x86_64
OS: Mac OS
unspecified
medium
Target Milestone: ---
: ---
Assignee: Van Halbert
QA Contact: Filip Elias
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2016-04-04 13:58 UTC by Cojan van Ballegooijen
Modified: 2016-05-16 12:46 UTC (History)
7 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2016-05-09 13:07:15 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
Mysql database script (1.46 KB, text/plain)
2016-04-04 13:58 UTC, Cojan van Ballegooijen
no flags Details
JBDS DV Project files (86.15 KB, application/zip)
2016-04-04 14:01 UTC, Cojan van Ballegooijen
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker TEIID-4127 0 Major Closed Command DB Logging - SQLCMD attribute VARCHAR(8196) is too small for large queries 2018-08-15 13:52:06 UTC

Description Cojan van Ballegooijen 2016-04-04 13:58:55 UTC
Created attachment 1143357 [details]
Mysql database script

Description of problem:
Setup DV to use the command logging database instead of log files.
Was testing a large join with a left outer join to test another issue and run into 
an issue with 
Version-Release number of selected component (if applicable):
6.4.3

How reproducible:
See below

Steps to Reproduce:
1. Setup MySQL
2. execute politie_mysql.sql sample database // see attachment
3. Setup DV with connection to mysql
4. Setup datasource in DV/EAP to mysql // java:Politie
5. Deploy VDB named DutchPolice.vdb // see attachment
6. Execute VDB DutchPolice and execute following SQL statement:
SELECT * FROM Politie_VBL.joined;

Actual results:
15:14:48,880 ERROR [stderr] (Worker1_QueryProcessorQueue512) Mon Apr 04 15:14:48 CEST 2016 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
15:14:48,897 INFO  [org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl] (pool-1-thread-1) HHH000010: On release of batch it still contained JDBC statements
15:14:48,898 WARN  [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (pool-1-thread-1) SQL Error: 22001, SQLState: 22001
15:14:48,898 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (pool-1-thread-1) Value too long for column "SQLCMD VARCHAR(8196) SELECTIVITY 5": "'SELECT g_0.tab2 AS c_0 FROM Politie.tab2 AS g_0 WHERE (g_0.tab2 IN (1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, ... (339844)"; SQL statement:
insert into commandlog (applicationname, executionid, modelname, principal, queryplan, requestid, row_count, sessionid, sourcecommand, sourcerequestid, sqlcmd, eventtype, logtime, transactionid, translatorname, vdbname, vdbversion, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [22001-168]
15:14:48,898 WARN  [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (pool-1-thread-1) SQL Error: 22001, SQLState: 22001
15:14:48,899 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (pool-1-thread-1) Value too long for column "SQLCMD VARCHAR(8196) SELECTIVITY 5": "'SELECT g_0.tab2 AS c_0 FROM Politie.tab2 AS g_0 WHERE (g_0.tab2 IN (1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, ... (339844)"; SQL statement:
insert into commandlog (applicationname, executionid, modelname, principal, queryplan, requestid, row_count, sessionid, sourcecommand, sourcerequestid, sqlcmd, eventtype, logtime, transactionid, translatorname, vdbname, vdbversion, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [22001-168]
15:14:48,900 ERROR [org.hibernate.engine.jdbc.batch.internal.BatchingBatch] (pool-1-thread-1) HHH000315: Exception executing batch [could not execute batch]
15:14:48,902 WARN  [com.arjuna.ats.arjuna] (pool-1-thread-1) ARJUNA012125: TwoPhaseCoordinator.beforeCompletion - failed for SynchronizationImple< 0:ffffc0a800ba:-1938a88d:570268b2:aa, org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization@24d482de >: javax.persistence.PersistenceException: org.hibernate.exception.DataException: could not execute batch
	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1387) [hibernate-entitymanager-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1310) [hibernate-entitymanager-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1316) [hibernate-entitymanager-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.ejb.AbstractEntityManagerImpl$CallbackExceptionMapperImpl.mapManagedFlushFailure(AbstractEntityManagerImpl.java:1510) [hibernate-entitymanager-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:114) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:53) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:273)
	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:93)
	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1189)
	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:91) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:282) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:330) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:242) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:89) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:185) [jboss-as-ee-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185) [jboss-as-ee-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73) [jboss-as-ee-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.teiid.service.DatabaseServiceLocal$$$view1.log(Unknown Source) [database-service.jar:]
	at org.teiid.logger.DatabaseAppender.publish(DatabaseAppender.java:47) [database-logging-appender-1.1.0.redhat-7.jar:1.1.0.redhat-7]
	at org.jboss.logmanager.handlers.AsyncHandler$AsyncTask.run(AsyncHandler.java:196) [jboss-logmanager-1.5.4.Final-redhat-1.jar:1.5.4.Final-redhat-1]
	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_74]
Caused by: org.hibernate.exception.DataException: could not execute batch
	at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:135) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:124) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:122) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:101) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.execute(AbstractBatchImpl.java:161) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.executeBatch(JdbcCoordinatorImpl.java:207) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:390) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:303) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:349) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:56) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1195) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:404) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:109) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	... 39 more
Caused by: org.h2.jdbc.JdbcBatchUpdateException: Value too long for column "SQLCMD VARCHAR(8196) SELECTIVITY 5": "'SELECT g_0.tab2 AS c_0 FROM Politie.tab2 AS g_0 WHERE (g_0.tab2 IN (1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, ... (339844)"; SQL statement:
insert into commandlog (applicationname, executionid, modelname, principal, queryplan, requestid, row_count, sessionid, sourcecommand, sourcerequestid, sqlcmd, eventtype, logtime, transactionid, translatorname, vdbname, vdbversion, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [22001-168]
	at org.h2.jdbc.JdbcPreparedStatement.executeBatch(JdbcPreparedStatement.java:1121)
	at org.jboss.jca.adapters.jdbc.WrappedStatement.executeBatch(WrappedStatement.java:1077)
	at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:113) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	... 49 more

15:14:48,908 ERROR [org.jboss.as.ejb3.invocation] (pool-1-thread-1) JBAS014134: EJB Invocation failed on component teiid-database-service for method public abstract void org.teiid.service.DatabaseServiceLocal.log(org.teiid.logging.CommandLogMessage): javax.ejb.EJBTransactionRolledbackException: Transaction rolled back
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleEndTransactionException(CMTTxInterceptor.java:137) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:117) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:282) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:330) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:242) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:89) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:185) [jboss-as-ee-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185) [jboss-as-ee-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation-1.1.2.Final-redhat-1.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73) [jboss-as-ee-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	at org.teiid.service.DatabaseServiceLocal$$$view1.log(Unknown Source) [database-service.jar:]
	at org.teiid.logger.DatabaseAppender.publish(DatabaseAppender.java:47) [database-logging-appender-1.1.0.redhat-7.jar:1.1.0.redhat-7]
	at org.jboss.logmanager.handlers.AsyncHandler$AsyncTask.run(AsyncHandler.java:196) [jboss-logmanager-1.5.4.Final-redhat-1.jar:1.5.4.Final-redhat-1]
	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_74]
Caused by: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1201)
	at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126)
	at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:75)
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.endTransaction(CMTTxInterceptor.java:91) [jboss-as-ejb3-7.5.6.Final-redhat-2.jar:7.5.6.Final-redhat-2]
	... 30 more
Caused by: javax.persistence.PersistenceException: org.hibernate.exception.DataException: could not execute batch
	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1387) [hibernate-entitymanager-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1310) [hibernate-entitymanager-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1316) [hibernate-entitymanager-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.ejb.AbstractEntityManagerImpl$CallbackExceptionMapperImpl.mapManagedFlushFailure(AbstractEntityManagerImpl.java:1510) [hibernate-entitymanager-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:114) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:53) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76)
	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:273)
	at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:93)
	at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
	at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1189)
	... 33 more
Caused by: org.hibernate.exception.DataException: could not execute batch
	at org.hibernate.exception.internal.SQLStateConversionDelegate.convert(SQLStateConversionDelegate.java:135) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:124) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:122) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.doExecuteBatch(BatchingBatch.java:101) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl.execute(AbstractBatchImpl.java:161) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.executeBatch(JdbcCoordinatorImpl.java:207) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:390) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:303) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:349) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:56) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1195) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:404) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:109) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	... 39 more
Caused by: org.h2.jdbc.JdbcBatchUpdateException: Value too long for column "SQLCMD VARCHAR(8196) SELECTIVITY 5": "'SELECT g_0.tab2 AS c_0 FROM Politie.tab2 AS g_0 WHERE (g_0.tab2 IN (1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, ... (339844)"; SQL statement:
insert into commandlog (applicationname, executionid, modelname, principal, queryplan, requestid, row_count, sessionid, sourcecommand, sourcerequestid, sqlcmd, eventtype, logtime, transactionid, translatorname, vdbname, vdbversion, id) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [22001-168]
	at org.h2.jdbc.JdbcPreparedStatement.executeBatch(JdbcPreparedStatement.java:1121)
	at org.jboss.jca.adapters.jdbc.WrappedStatement.executeBatch(WrappedStatement.java:1077)
	at org.hibernate.engine.jdbc.batch.internal.BatchingBatch.performExecution(BatchingBatch.java:113) [hibernate-core-4.2.22.Final-redhat-1.jar:4.2.22.Final-redhat-1]
	... 49 more

Expected results:
SQL statement should be inserted without any issues into the command_log table

Additional info:

Comment 2 Cojan van Ballegooijen 2016-04-04 14:01:41 UTC
Created attachment 1143358 [details]
JBDS DV Project files


Note You need to log in before you can comment on or make changes to this bug.