2

Class UserPrincipal extends the Spring class User. Most of the time this works with no problem. But no we want to put some data from the UserPrincipal to log. So we created custom Converters for the logback to add USer and Session info to the log.

Problem is that the User info is asked from the principal that is gotten from Authentication. It gives error UserPrincipal cannot be cast to UserPrincipal.

I know about the classloader problem that causes this. Here the problem is probably that the converter classes created for the logback are not in spring context. Is there a way to get this working or is there any other way to get the User and Session data to log ?

EDIT UserConverter

public class UserConverter extends ClassicConverter{
    @Override
    public String convert(ILoggingEvent iLoggingEvent){
        try {
            Long userId = SecurityUtils.getClientId();
            if (userId != null) {
                return Long.toString(userId);
            }
        }catch(Throwable ex){
            ex.printStackTrace();
            return "NO_USER";
        }
        return "NO_USER";
    }
}

The part where the error comes. This is in SecurityUtils

SecurityContext securityContext = SecurityContextHolder.getContext();
        Authentication authentication = securityContext.getAuthentication();
        UserPrincipal userPrincipal = (UserPrincipal) authentication.getPrincipal();

Error

java.lang.ClassCastException: ee.rmit.ekat.security.model.UserPrincipal cannot be cast to ee.rmit.ekat.security.model.UserPrincipal
    at ee.rmit.ekat.security.SecurityUtils.getClientId(SecurityUtils.java:72)
    at ee.rmit.ekat.service.logging.UserConverter.convert(UserConverter.java:14)
    at ee.rmit.ekat.service.logging.UserConverter.convert(UserConverter.java:10)
    at ch.qos.logback.core.pattern.FormattingConverter.write(FormattingConverter.java:36)
    at ch.qos.logback.core.pattern.PatternLayoutBase.writeLoopOnConverters(PatternLayoutBase.java:118)
    at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:141)
    at ch.qos.logback.classic.PatternLayout.doLayout(PatternLayout.java:1)
    at ch.qos.logback.core.encoder.LayoutWrappingEncoder.doEncode(LayoutWrappingEncoder.java:130)
    at ch.qos.logback.core.OutputStreamAppender.writeOut(OutputStreamAppender.java:187)
    at ch.qos.logback.core.FileAppender.writeOut(FileAppender.java:279)
    at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:212)
    at ch.qos.logback.core.rolling.RollingFileAppender.subAppend(RollingFileAppender.java:235)
    at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:100)
    at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:84)
    at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:51)
    at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:270)
    at ch.qos.logback.classic.Logger.callAppenders(Logger.java:257)
    at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:421)
    at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
    at ch.qos.logback.classic.Logger.log(Logger.java:765)
    at sun.reflect.GeneratedMethodAccessor61.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.jboss.logging.Slf4jLocationAwareLogger.doLog(Slf4jLocationAwareLogger.java:89)
    at org.jboss.logging.Slf4jLocationAwareLogger.doLogf(Slf4jLocationAwareLogger.java:82)
    at org.jboss.logging.Logger.tracef(Logger.java:301)
    at org.hibernate.type.descriptor.sql.BasicExtractor.extract(BasicExtractor.java:51)
    at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:238)
    at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:234)
    at org.hibernate.type.AbstractStandardBasicType.nullSafeGet(AbstractStandardBasicType.java:224)
    at org.hibernate.type.AbstractStandardBasicType.hydrate(AbstractStandardBasicType.java:300)
    at org.hibernate.persister.entity.AbstractEntityPersister.hydrate(AbstractEntityPersister.java:2790)
    at org.hibernate.loader.Loader.loadFromResultSet(Loader.java:1729)
    at org.hibernate.loader.Loader.instanceNotYetLoaded(Loader.java:1655)
    at org.hibernate.loader.Loader.getRow(Loader.java:1544)
    at org.hibernate.loader.Loader.getRowFromResultSet(Loader.java:727)
    at org.hibernate.loader.Loader.processResultSet(Loader.java:972)
    at org.hibernate.loader.Loader.doQuery(Loader.java:930)
    at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:336)
    at org.hibernate.loader.Loader.doList(Loader.java:2617)
    at org.hibernate.loader.Loader.doList(Loader.java:2600)
    at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2429)
    at org.hibernate.loader.Loader.list(Loader.java:2424)
    at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:501)
    at org.hibernate.hql.internal.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:371)
    at org.hibernate.engine.query.spi.HQLQueryPlan.performList(HQLQueryPlan.java:216)
    at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1326)
    at org.hibernate.internal.QueryImpl.list(QueryImpl.java:87)
    at org.hibernate.jpa.internal.QueryImpl.list(QueryImpl.java:606)
    at org.hibernate.jpa.internal.QueryImpl.getResultList(QueryImpl.java:483)
    at org.springframework.data.jpa.repository.query.JpaQueryExecution$CollectionExecution.doExecute(JpaQueryExecution.java:121)
    at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:85)
    at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:116)
    at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:106)
    at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:483)
    at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:461)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:56)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:99)
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:282)
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:136)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:133)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.data.repository.core.support.SurroundingTransactionDetectorMethodInterceptor.invoke(SurroundingTransactionDetectorMethodInterceptor.java:57)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:213)
    at com.sun.proxy.$Proxy138.getProductSearchResult(Unknown Source)
    at ee.rmit.ekat.service.ProductService.getUserProducts(ProductService.java:424)
    at ee.rmit.ekat.service.ProductService$$FastClassBySpringCGLIB$$9ed2c7ba.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:669)
    at ee.rmit.ekat.service.ProductService$$EnhancerBySpringCGLIB$$dc181e9d.getUserProducts(<generated>)
    at ee.rmit.ekat.web.rest.resource.efront.EfrontResource.userProducts(EfrontResource.java:157)
    at ee.rmit.ekat.web.rest.resource.efront.EfrontResource$$FastClassBySpringCGLIB$$f2133a41.invoke(<generated>)
    at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
    at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:738)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
    at org.springframework.security.access.intercept.aopalliance.MethodSecurityInterceptor.invoke(MethodSecurityInterceptor.java:69)
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
    at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:673)
    at ee.rmit.ekat.web.rest.resource.efront.EfrontResource$$EnhancerBySpringCGLIB$$91091966.userProducts(<generated>)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205)
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:133)
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:97)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:827)
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:738)
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:967)
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:901)
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:970)
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:861)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:635)
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:846)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:742)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.boot.web.filter.ApplicationContextHeaderFilter.doFilterInternal(ApplicationContextHeaderFilter.java:55)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.CorsFilter.doFilterInternal(CorsFilter.java:96)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:110)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:317)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:127)
    at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:91)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:114)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:137)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:111)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:170)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at ee.rmit.ekat.security.jwt.JWTFilter.doFilter(JWTFilter.java:37)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:116)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:64)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:105)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:56)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:331)
    at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:214)
    at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:177)
    at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)
    at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:262)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:99)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.HttpPutFormContentFilter.doFilterInternal(HttpPutFormContentFilter.java:105)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:81)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:197)
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:198)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:478)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:80)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:799)
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1455)
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    at java.lang.Thread.run(Thread.java:748)
Marko Taht
  • 1,448
  • 1
  • 20
  • 40

5 Answers5

2

If this is really an issue with different ClassLoaders and you only want the Id or another "known" field from this instance you have two options:

  1. Read the Field using Reflection (e.g. authentication.getPrincipal().getDeclaredField("userId").get(authentication.getPrincipal()) or
  2. Make a "Serialization Roundtrip" (e.g. (UserPrincipal) org.apache.commons.lang3.SerializationUtils.roundtrip(authentication.getPrincipal())) if the Object implements Serializable
M.F
  • 403
  • 2
  • 10
1

The problem is that the method authentication.getPrincipal() cannot be converted to a UserPrincipal object.

You should look what's the instance of authentication.getPrincipal().

EDIT: now that I see your stacktrace, it must be a ClassLoader related issue.

Mathias G.
  • 4,875
  • 3
  • 39
  • 60
  • It works everywhere else, except when called from the converter. – Marko Taht Feb 14 '18 at 11:19
  • Still I would try to find out what's the class of the 'authentication.getPrincipal()' method. Fact is that it won't be a UserPrincipal, otherwise you wouldn't get the exception. – Mathias G. Feb 14 '18 at 11:22
  • 2
    I added the error also. You can see it tries to cast USerPrincipal into UserPrincipal – Marko Taht Feb 14 '18 at 11:23
0

You can use BeanUtils.copyProperties instead of casting

Authentication authentication = securityContext.getAuthentication();
UserPrincipal userPrincipal = new UserPrincipal();
BeanUtils.copyProperties(userPrincipal, securityContext.getAuthentication());

https://commons.apache.org/proper/commons-beanutils/apidocs/org/apache/commons/beanutils/BeanUtils.html#copyProperties-java.lang.Object-java.lang.Object-

cagridursun
  • 114
  • 4
  • Might work. Cant use. User class, the one UserPrincipal extends does not have no argument constructor. And i cant modify User. – Marko Taht Feb 14 '18 at 12:42
0

String.valueOf(longvalue) Try this

Muthu
  • 156
  • 8
0

Since this approach didnt work. We ended up using MDC to put the keys and AOP @Pointcut and @Around the inject the data into the logger.

Marko Taht
  • 1,448
  • 1
  • 20
  • 40