Skip to content

SQL statement is printed in exceptions despite eclipselink.logging.level.sql is OFF #1408

@11rx4f

Description

@11rx4f

Problem Description

EclipseLink can print SQL statement sent to the database.
It is described in following document.
https://wiki.eclipse.org/EclipseLink/Examples/JPA/Logging

In this doc, the persistence unit property eclipselink.logging.level.sql has 9 log levels, and logging in exceptions can also be controlled by the property.
but the SQL statement is printed in exceptions despite eclipselink.logging.level.sql is OFF.

Environment

  • Server: GlassFish 6.2.4 (using eclipselink 3.0.2)
  • Java Version:
$ java -version
openjdk version "11.0.12" 2021-07-20
OpenJDK Runtime Environment Temurin-11.0.12+7 (build 11.0.12+7)
OpenJDK 64-Bit Server VM Temurin-11.0.12+7 (build 11.0.12+7, mixed mode)

Steps to Reproduce using GlassFish

jpasample.zip

  1. start-domain
  2. start-database
  3. deploy jpasample.jar
  4. execute following command
java -cp ${path2glassfish}/glassfish6/glassfish/lib/gf-client.jar:${path2app}/jpasample.jar com.example.App
  1. check server.log, you can see the SQL statement
[2022-01-24T14:16:57.522+0900] [glassfish 6.2] [WARNING] [][org.eclipse.persistence.session./file:/glassfish6/glassfish/domains/domain1/applications/jpasample/_SQLLog] [tid: _ThreadID=54 _ThreadName=p: thread-pool-1; w: 2] [timeMillis: 1643001417522] [levelValue: 900] [[

Local Exception Stack:
Exception [EclipseLink-4002] (Eclipse Persistence Services - 3.0.2.v202107160933): org.eclipse.persistence.exceptions.DatabaseException
Internal Exception: org.apache.derby.shared.common.error.DerbySQLIntegrityConstraintViolationException: The statement was aborted because it would have caused a duplicate key value in a unique or primary key constraint or unique index identified by 'SQL0000000004-a352c053-017e-7c03-e17b-000005f4ff1f' defined on 'DEPT'.
Error Code: 20000
Call: INSERT INTO DEPT (DEPTNO, dname, LOC) VALUES (?, ?, ?)
        bind => [1, dname, loc]
Query: InsertObjectQuery(com.example.entity.Dept@52683a43)
        at org.eclipse.persistence.exceptions.DatabaseException.sqlException(DatabaseException.java:334)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeDirectNoSelect(DatabaseAccessor.java:908)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeNoSelect(DatabaseAccessor.java:970)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.basicExecuteCall(DatabaseAccessor.java:640)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeCall(DatabaseAccessor.java:567)
        at org.eclipse.persistence.internal.sessions.AbstractSession.basicExecuteCall(AbstractSession.java:2051)
        at org.eclipse.persistence.sessions.server.ClientSession.executeCall(ClientSession.java:312)
        at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:282)
        at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.executeCall(DatasourceCallQueryMechanism.java:268)
        at org.eclipse.persistence.internal.queries.DatasourceCallQueryMechanism.insertObject(DatasourceCallQueryMechanism.java:421)
        at org.eclipse.persistence.internal.queries.StatementQueryMechanism.insertObject(StatementQueryMechanism.java:175)
        at org.eclipse.persistence.internal.queries.StatementQueryMechanism.insertObject(StatementQueryMechanism.java:191)
        at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.insertObjectForWrite(DatabaseQueryMechanism.java:507)
        at org.eclipse.persistence.queries.InsertObjectQuery.executeCommit(InsertObjectQuery.java:83)
        at org.eclipse.persistence.queries.InsertObjectQuery.executeCommitWithChangeSet(InsertObjectQuery.java:94)
        at org.eclipse.persistence.internal.queries.DatabaseQueryMechanism.executeWriteWithChangeSet(DatabaseQueryMechanism.java:319)
        at org.eclipse.persistence.queries.WriteObjectQuery.executeDatabaseQuery(WriteObjectQuery.java:61)
        at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:912)
        at org.eclipse.persistence.queries.DatabaseQuery.executeInUnitOfWork(DatabaseQuery.java:811)
        at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWorkObjectLevelModifyQuery(ObjectLevelModifyQuery.java:112)
        at org.eclipse.persistence.queries.ObjectLevelModifyQuery.executeInUnitOfWork(ObjectLevelModifyQuery.java:89)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.internalExecuteQuery(UnitOfWorkImpl.java:3008)
        at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1844)
        at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1826)
        at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1776)
        at org.eclipse.persistence.internal.sessions.CommitManager.commitNewObjectsForClassWithChangeSet(CommitManager.java:248)
        at org.eclipse.persistence.internal.sessions.CommitManager.commitAllObjectsWithChangeSet(CommitManager.java:147)
        at org.eclipse.persistence.internal.sessions.AbstractSession.writeAllObjectsWithChangeSet(AbstractSession.java:4340)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabase(UnitOfWorkImpl.java:1507)
        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.commitToDatabaseWithChangeSet(UnitOfWorkImpl.java:1597)        at org.eclipse.persistence.internal.sessions.UnitOfWorkImpl.issueSQLbeforeCompletion(UnitOfWorkImpl.java:3285)
        at org.eclipse.persistence.internal.sessions.RepeatableWriteUnitOfWork.issueSQLbeforeCompletion(RepeatableWriteUnitOfWork.java:369)
        at org.eclipse.persistence.transaction.AbstractSynchronizationListener.beforeCompletion(AbstractSynchronizationListener.java:163)
        at org.eclipse.persistence.transaction.JTASynchronizationListener.beforeCompletion(JTASynchronizationListener.java:70)
        at com.sun.enterprise.transaction.JavaEETransactionImpl.commit(JavaEETransactionImpl.java:437)
        at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:806)
        at com.sun.enterprise.transaction.UserTransactionImpl.commit(UserTransactionImpl.java:174)
        at com.example.log.SQLLogEJB.insertEntity(SQLLogEJB.java:43)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at org.glassfish.exousia.AuthorizationService.lambda$invokeBeanMethod$6(AuthorizationService.java:501)
        at org.glassfish.exousia.AuthorizationService.runInScope(AuthorizationService.java:577)
        at org.glassfish.exousia.AuthorizationService.invokeBeanMethod(AuthorizationService.java:501)
        at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:295)
        at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:4306)
        at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:603)
        at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:809)
        at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:552)
        at org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:81)
        at org.jboss.weld.module.ejb.SessionBeanInterceptor.aroundInvoke(SessionBeanInterceptor.java:52)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:871)
        at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:808)
        at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:552)
        at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doCall(SystemInterceptorProxy.java:136)
        at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:113)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:871)
        at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:808)
        at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:348)
        at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:4281)
        at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:4271)
        at com.sun.ejb.containers.EJBObjectInvocationHandler.invoke(EJBObjectInvocationHandler.java:173)
        at com.sun.ejb.containers.EJBObjectInvocationHandlerDelegate.invoke(EJBObjectInvocationHandlerDelegate.java:54)
        at com.sun.proxy.$Proxy309.insertEntity(Unknown Source)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:566)
        at com.sun.corba.ee.impl.presentation.rmi.ReflectiveTie.dispatchToMethod(ReflectiveTie.java:122)
        at com.sun.corba.ee.impl.presentation.rmi.ReflectiveTie._invoke(ReflectiveTie.java:152)
        at com.sun.corba.ee.impl.protocol.ServerRequestDispatcherImpl.dispatchToServant(ServerRequestDispatcherImpl.java:501)
        at com.sun.corba.ee.impl.protocol.ServerRequestDispatcherImpl.dispatch(ServerRequestDispatcherImpl.java:172)
        at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.handleRequestRequest(MessageMediatorImpl.java:1529)
        at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.handleRequest(MessageMediatorImpl.java:1405)
        at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.handleInput(MessageMediatorImpl.java:910)
        at com.sun.corba.ee.impl.protocol.giopmsgheaders.RequestMessage_1_2.callback(RequestMessage_1_2.java:192)
        at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.handleRequest(MessageMediatorImpl.java:674)
        at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.dispatch(MessageMediatorImpl.java:476)
        at com.sun.corba.ee.impl.protocol.MessageMediatorImpl.doWork(MessageMediatorImpl.java:2202)
        at com.sun.corba.ee.impl.threadpool.ThreadPoolImpl$WorkerThread.performWork(ThreadPoolImpl.java:476)
        at com.sun.corba.ee.impl.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:519)
Caused by: org.apache.derby.shared.common.error.DerbySQLIntegrityConstraintViolationException: The statement was aborted because it would have caused a duplicate key value in a unique or primary key constraint or unique index identified by 'SQL0000000004-a352c053-017e-7c03-e17b-000005f4ff1f' defined on 'DEPT'.
        at org.apache.derby.client.am.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:85)
        at org.apache.derby.client.am.SqlException.getSQLException(SqlException.java:325)
        at org.apache.derby.client.am.ClientPreparedStatement.executeUpdate(ClientPreparedStatement.java:405)
        at com.sun.gjc.spi.base.PreparedStatementWrapper.executeUpdate(PreparedStatementWrapper.java:101)
        at org.eclipse.persistence.internal.databaseaccess.DatabaseAccessor.executeDirectNoSelect(DatabaseAccessor.java:898)
        ... 88 more
Caused by: ERROR 23505: The statement was aborted because it would have caused a duplicate key value in a unique or primary key constraint or unique index identified by 'SQL0000000004-a352c053-017e-7c03-e17b-000005f4ff1f' defined on 'DEPT'.
        at org.apache.derby.client.am.ClientStatement.completeExecute(ClientStatement.java:1868)
        at org.apache.derby.client.net.NetStatementReply.parseEXCSQLSTTreply(NetStatementReply.java:323)
        at org.apache.derby.client.net.NetStatementReply.readExecute(NetStatementReply.java:72)
        at org.apache.derby.client.net.StatementReply.readExecute(StatementReply.java:59)
        at org.apache.derby.client.net.NetPreparedStatement.readExecute_(NetPreparedStatement.java:167)
        at org.apache.derby.client.am.ClientPreparedStatement.readExecute(ClientPreparedStatement.java:1844)
        at org.apache.derby.client.am.ClientPreparedStatement.flowExecute(ClientPreparedStatement.java:2133)
        at org.apache.derby.client.am.ClientPreparedStatement.executeUpdateX(ClientPreparedStatement.java:410)
        at org.apache.derby.client.am.ClientPreparedStatement.executeUpdate(ClientPreparedStatement.java:396)
        ... 90 more
]]

Impact of Issue

SQL statement is always visible in exceptions

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions