ClassCastException due to EntityType.toLoggableString calling EntityPersister.getIdentifier on a proxy ------------------------------------------------------------------------------------------------------ Key: HHH-7171 URL: https://hibernate.onjira.com/browse/HHH-7171 Project: Hibernate ORM Issue Type: Bug Components: core Affects Versions: 4.1.1 Reporter: Anders Wallgren Attachments: HHH-7171.patch With debug logging enabled, EntityType.toLoggableString ends up being called on a proxied entity. toLoggableString calls getIdentifier without first checking for a proxy (as other code in the EntityType class do). The result is a ClassCastException when the tuplizer getIdentifier method attempts to invoke a method from an abstract class on a proxy: {code} org.springframework.orm.hibernate4.HibernateSystemException: IllegalArgumentException occurred calling getter of com.electriccloud.domain.AbstractEntity.id; nested exception is org.hibernate.PropertyAccessException: IllegalArgumentException occurred calling getter of com.electriccloud.domain.AbstractEntity.id at org.springframework.orm.hibernate4.SessionFactoryUtils.convertHibernateAccessException(SessionFactoryUtils.java:206) ~[spring-orm-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.orm.hibernate4.HibernateTransactionManager.convertHibernateAccessException(HibernateTransactionManager.java:606) ~[spring-orm-3.1.1.RELEASE.jar:3.1.1.RELEASE] at com.electriccloud.hibernate4.TransactionManagerImpl.convertHibernateAccessException(TransactionManagerImpl.java:45) ~[ec-hibernate4-1.0.0-SNAPSHOT.jar:] at org.springframework.orm.hibernate4.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:488) ~[spring-orm-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:754) ~[spring-tx-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:723) ~[spring-tx-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:393) ~[spring-tx-3.1.1.RELEASE.jar:3.1.1.RELEASE] at com.electriccloud.transaction.TransactionAspectImpl.withTransaction(TransactionAspectImpl.java:211) ~[ec-transaction-1.0.0-SNAPSHOT.jar:] at com.electriccloud.deploy.dao.transaction.DeployTransactionAspect.withTransaction(DeployTransactionAspect.java:30) ~[deploy-dao-1.0.0-SNAPSHOT.jar:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.6.0_31] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[na:1.6.0_31] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[na:1.6.0_31] at java.lang.reflect.Method.invoke(Method.java:597) ~[na:1.6.0_31] at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:622) ~[spring-aop-3.1.1.RELEASE.jar:3.1.1.RELEASE] at com.electriccloud.deploy.rest.ApplicationController$$EnhancerByCGLIB$$b2458e5d.list(<generated>) ~[cglib-2.2.2.jar:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.6.0_31] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[na:1.6.0_31] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[na:1.6.0_31] at java.lang.reflect.Method.invoke(Method.java:597) ~[na:1.6.0_31] at org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:213) ~[spring-web-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:126) ~[spring-web-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:96) ~[spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:617) ~[spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:578) ~[spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80) ~[spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923) ~[spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852) ~[spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE] at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:778) [spring-webmvc-3.1.1.RELEASE.jar:3.1.1.RELEASE] at javax.servlet.http.HttpServlet.service(HttpServlet.java:735) [servlet-api-3.0.jar:na] at javax.servlet.http.HttpServlet.service(HttpServlet.java:848) [servlet-api-3.0.jar:na] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:594) [jetty-servlet-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:485) [jetty-servlet-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:119) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:521) [jetty-security-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:233) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1065) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:412) [jetty-servlet-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:192) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:999) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:250) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:149) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:111) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.Server.handle(Server.java:351) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:451) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:916) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:634) [jetty-http-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:230) [jetty-http-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:76) [jetty-server-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:609) [jetty-io-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:45) [jetty-io-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:599) [jetty-util-8.1.0.v20120127.jar:8.1.0.v20120127] at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:534) [jetty-util-8.1.0.v20120127.jar:8.1.0.v20120127] at java.lang.Thread.run(Thread.java:662) [na:1.6.0_31] Caused by: org.hibernate.PropertyAccessException: IllegalArgumentException occurred calling getter of com.electriccloud.domain.AbstractEntity.id at org.hibernate.property.BasicPropertyAccessor$BasicGetter.get(BasicPropertyAccessor.java:187) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.hibernate.tuple.entity.AbstractEntityTuplizer.getIdentifier(AbstractEntityTuplizer.java:341) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.hibernate.persister.entity.AbstractEntityPersister.getIdentifier(AbstractEntityPersister.java:4273) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.hibernate.type.EntityType.toLoggableString(EntityType.java:507) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.hibernate.internal.util.EntityPrinter.toString(EntityPrinter.java:79) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.hibernate.internal.util.EntityPrinter.toString(EntityPrinter.java:121) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.hibernate.event.internal.AbstractFlushingEventListener.logFlushResults(AbstractFlushingEventListener.java:131) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.hibernate.event.internal.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:107) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:51) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1127) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:325) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.hibernate.engine.transaction.internal.jdbc.JdbcTransaction.beforeTransactionCommit(JdbcTransaction.java:101) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.hibernate.engine.transaction.spi.AbstractTransactionImpl.commit(AbstractTransactionImpl.java:175) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] at org.springframework.orm.hibernate4.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:480) ~[spring-orm-3.1.1.RELEASE.jar:3.1.1.RELEASE] ... 57 common frames omitted Caused by: java.lang.IllegalArgumentException: java.lang.ClassCastException@332b25db at sun.reflect.GeneratedMethodAccessor37.invoke(Unknown Source) ~[na:na] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[na:1.6.0_31] at java.lang.reflect.Method.invoke(Method.java:597) ~[na:1.6.0_31] at org.hibernate.property.BasicPropertyAccessor$BasicGetter.get(BasicPropertyAccessor.java:164) ~[hibernate-core-4.1.1.Final-PATCH1.jar:4.1.1.Final-PATCH1] ... 70 common frames omitted {code}