Error on redeploying Autowakeup application

[SudarsananRengarajan]

Hi Team,

Am facing error on re-deploying autowakeup application if its already running.

Application deployment succeeds if that is new deployment.

2016-10-21T10:00:53.06-0400 [APP/0]      ERR Exception in thread "main" java.lang.RuntimeException: java.lang.reflect.InvocationTargetException
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:62)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at java.lang.Thread.run(Thread.java:745)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR Caused by: java.lang.reflect.InvocationTargetException
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at java.lang.reflect.Method.invoke(Method.java:497)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:54)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    ... 1 more
2016-10-21T10:00:53.06-0400 [APP/0]      ERR Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'getLogClient' defined in org.cloudfoundry.autosleep.access.cloudfoundry.config.CloudfoundryClientBuilder: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.cloudfoundry.logging.LoggingClient]: Factory method 'getLogClient' threw exception; nested exception is org.springframework.context.ApplicationContextException: Failed to build client; nested exception is error="access_denied", error_description="Error requesting access token."
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:599)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.instantiateUsingFactoryMethod(AbstractAutowireCapableBeanFactory.java:1123)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBeanInstance(AbstractAutowireCapableBeanFactory.java:1018)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:510)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:482)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.AbstractBeanFactory$1.getObject(AbstractBeanFactory.java:306)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:230)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:302)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:197)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:772)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:839)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:538)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:766)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.boot.SpringApplication.createAndRefreshContext(SpringApplication.java:361)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.boot.SpringApplication.run(SpringApplication.java:307)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.boot.builder.SpringApplicationBuilder.run(SpringApplicationBuilder.java:134)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.boot.builder.SpringApplicationBuilder.configureAsChildIfNecessary(SpringApplicationBuilder.java:147)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.boot.builder.SpringApplicationBuilder.run(SpringApplicationBuilder.java:130)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.cloudfoundry.autosleep.WakeUpApplication.main(WakeUpApplication.java:42)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    ... 6 more
2016-10-21T10:00:53.06-0400 [APP/0]      ERR Caused by: org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.cloudfoundry.logging.LoggingClient]: Factory method 'getLogClient' threw exception; nested exception is org.springframework.context.ApplicationContextException: Failed to build client; nested exception is error="access_denied", error_description="Error requesting access token."
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:189)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.ConstructorResolver.instantiateUsingFactoryMethod(ConstructorResolver.java:588)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    ... 24 more
2016-10-21T10:00:53.06-0400 [APP/0]      ERR Caused by: org.springframework.context.ApplicationContextException: Failed to build client; nested exception is error="access_denied", error_description="Error requesting access token."
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.cloudfoundry.autosleep.access.cloudfoundry.config.CloudfoundryClientBuilder.buildIfNeeded(CloudfoundryClientBuilder.java:97)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.cloudfoundry.autosleep.access.cloudfoundry.config.CloudfoundryClientBuilder.getLogClient(CloudfoundryClientBuilder.java:116)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.cloudfoundry.autosleep.access.cloudfoundry.config.CloudfoundryClientBuilder$$EnhancerBySpringCGLIB$$c57feb95.CGLIB$getLogClient$0(<generated>)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.cloudfoundry.autosleep.access.cloudfoundry.config.CloudfoundryClientBuilder$$EnhancerBySpringCGLIB$$c57feb95$$FastClassBySpringCGLIB$$dee737bd.invoke(<generated>)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.cglib.proxy.MethodProxy.invokeSuper(MethodProxy.java:228)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.context.annotation.ConfigurationClassEnhancer$BeanMethodInterceptor.intercept(ConfigurationClassEnhancer.java:356)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.cloudfoundry.autosleep.access.cloudfoundry.config.CloudfoundryClientBuilder$$EnhancerBySpringCGLIB$$c57feb95.getLogClient(<generated>)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at java.lang.reflect.Method.invoke(Method.java:497)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.beans.factory.support.SimpleInstantiationStrategy.instantiate(SimpleInstantiationStrategy.java:162)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    ... 25 more
2016-10-21T10:00:53.06-0400 [APP/0]      ERR Caused by: error="access_denied", error_description="Error requesting access token."
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.security.oauth2.client.token.OAuth2AccessTokenSupport.retrieveToken(OAuth2AccessTokenSupport.java:145)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.security.oauth2.client.token.grant.password.ResourceOwnerPasswordAccessTokenProvider.obtainAccessToken(ResourceOwnerPasswordAccessTokenProvider.java:47)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.security.oauth2.client.OAuth2RestTemplate.acquireAccessToken(OAuth2RestTemplate.java:221)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.security.oauth2.client.OAuth2RestTemplate.getAccessToken(OAuth2RestTemplate.java:173)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.security.oauth2.client.OAuth2RestTemplate.createRequest(OAuth2RestTemplate.java:105)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:592)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.security.oauth2.client.OAuth2RestTemplate.doExecute(OAuth2RestTemplate.java:128)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:572)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.springframework.web.client.RestTemplate.getForObject(RestTemplate.java:280)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.cloudfoundry.spring.util.AbstractSpringOperations.lambda$get$3(AbstractSpringOperations.java:85)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at org.cloudfoundry.spring.util.AbstractSpringOperations.lambda$null$1(AbstractSpringOperations.java:66)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at reactor.core.publisher.FluxYieldingEmitter$YieldingSignalEmitter.request(FluxYieldingEmitter.java:72)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at reactor.core.util.DeferredSubscription.request(DeferredSubscription.java:92)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at reactor.core.publisher.FluxPublishOn$PublishOnPipeline.run(FluxPublishOn.java:164)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at reactor.core.publisher.SchedulerGroup$TaskSubscriber.onNext(SchedulerGroup.java:1081)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at reactor.core.publisher.SchedulerGroup$TaskSubscriber.onNext(SchedulerGroup.java:1063)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at reactor.core.publisher.WorkQueueProcessor$QueueSubscriberLoop.run(WorkQueueProcessor.java:842)
2016-10-21T10:00:53.06-0400 [APP/0]      ERR    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
2016-10-21T10:00:53.07-0400 [APP/0]      ERR    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
2016-10-21T10:00:53.07-0400 [APP/0]      ERR    ... 1 more
2016-10-21T10:00:53.07-0400 [APP/0]      ERR Caused by: org.springframework.web.client.HttpClientErrorException: 401 Unauthorized
2016-10-21T10:00:53.07-0400 [APP/0]      ERR    at org.springframework.web.client.DefaultResponseErrorHandler.handleError(DefaultResponseErrorHandler.java:91)
2016-10-21T10:00:53.07-0400 [APP/0]      ERR    at org.springframework.security.oauth2.client.token.OAuth2AccessTokenSupport$AccessTokenErrorHandler.handleError(OAuth2AccessTokenSupport.java:244)
2016-10-21T10:00:53.07-0400 [APP/0]      ERR    at org.springframework.web.client.RestTemplate.handleResponse(RestTemplate.java:641)
2016-10-21T10:00:53.07-0400 [APP/0]      ERR    at org.springframework.web.client.RestTemplate.doExecute(RestTemplate.java:597)
2016-10-21T10:00:53.07-0400 [APP/0]      ERR    at org.springframework.web.client.RestTemplate.execute(RestTemplate.java:565)
2016-10-21T10:00:53.07-0400 [APP/0]      ERR    at org.springframework.security.oauth2.client.token.OAuth2AccessTokenSupport.retrieveToken(OAuth2AccessTokenSupport.java:137)
2016-10-21T10:00:53.07-0400 [APP/0]      ERR    ... 19 more

Thank you

Regards, Sudarsanan R

[gberche-orange]

Hi @SudarsananRengarajan Thanks for your report and sorry for the late reply.

Did you manage to reproduce the problem multiple times ? From the trace you provided, it seems the UAA was rejecting log in from login/password. Could it be related to a transient UAA unavailability or password change for the CC API account ?

If not, please enable verbose logs for the CC API exchanges by adding the following value to JAVA_OPTS environment variable so we trace trace down to the root cause (please send privately or filter out potentially sensitive logs there)

-Dlogging.level.cloudfoundry-client.request=DEBUG -Dlogging.level.cloudfoundry-client.response=DEBUG -Dlogging.level.cloudfoundry-client.token=DEBUG