Bug 1323721

Summary: Command DB Logging - SQLCMD attribute VARCHAR(8196) is too small for large queries
Product: [JBoss] JBoss Data Virtualization 6 Reporter: Cojan van Ballegooijen <cojan>
Component: TeiidAssignee: Van Halbert <vhalbert>
Status: CLOSED WONTFIX QA Contact: Filip Elias <felias>
Severity: medium Docs Contact:
Priority: unspecified    
Version: 6.2.0CC: aszczucz, blafond, drieden, jolee, mbaluch, thauser, vhalbert
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Mac OS   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-05-09 13:07:15 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Attachments:
Description Flags
Mysql database script
none
JBDS DV Project files none

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