VMware Tanzu Application Service for VMs

 View Only

 My spring-boot application start perfect and after some time start throwing bad_certificate error. Restarting the application fixes the issue. Any isight into the issue would be greatly appreciated.

YASIR MEHMOOD's profile image
YASIR MEHMOOD posted May 16, 2019 04:14 AM

 

Daniel Mikusa's profile image
Daniel Mikusa

Can you share any more details about this? How long does the app run before they occur? How long does the app run again after you restart? Is the time it runs after a restart consistent or is it different after every restart? What is the app doing when the error is generated? Can you include a stack trace of the error? Thanks!

YASIR MEHMOOD's profile image
YASIR MEHMOOD

Exception is large I will paste what I can

javax.net.ssl.SSLHandshakeException:javax.net.ssl.SSLHandshakeException 

Received fatal alert: bad_certificate 

at sun.reflect.GeneratedConstructorAccessor123.newInstance(Unknown Source)

at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)

at java.lang.reflect.Constructor.newInstance(Constructor.java:423)

at sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:1944)

at sun.net.www.protocol.http.HttpURLConnection$10.run(HttpURLConnection.java:1939)

at java.security.AccessController.doPrivileged(AccessController.java)

at sun.net.www.protocol.http.HttpURLConnection.getChainedException(HttpURLConnection.java:1938)

at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1508)

at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1492)

at sun.net.www.protocol.http.HttpURLConnection.getHeaderField(HttpURLConnection.java:3087)

at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:489)

at sun.net.www.protocol.https.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:347)

at feign.Client$Default.convertResponse(Client.java:152)

at feign.Client$Default.execute(Client.java:74)

 

YASIR MEHMOOD's profile image
YASIR MEHMOOD

at org.springframework.cloud.sleuth.instrument.web.client.feign.TraceFeignClient.execute(TraceFeignClient.java:92)

at org.springframework.cloud.netflix.feign.ribbon.FeignLoadBalancer.execute(FeignLoadBalancer.java:80)

at org.springframework.cloud.netflix.feign.ribbon.FeignLoadBalancer.execute(FeignLoadBalancer.java:48)

at com.netflix.client.AbstractLoadBalancerAwareClient$1.call(AbstractLoadBalancerAwareClient.java:104)

at com.netflix.loadbalancer.reactive.LoadBalancerCommand$3$1.call(LoadBalancerCommand.java:303)

at com.netflix.loadbalancer.reactive.LoadBalancerCommand$3$1.call(LoadBalancerCommand.java:287)

at rx.internal.util.ScalarSynchronousObservable$3.call(ScalarSynchronousObservable.java:231)

at rx.internal.util.ScalarSynchronousObservable$3.call(ScalarSynchronousObservable.java:228)

at rx.Observable.unsafeSubscribe(Observable.java:10151)

at rx.internal.operators.OnSubscribeConcatMap$ConcatMapSubscriber.drain(OnSubscribeConcatMap.java:286)

at rx.internal.operators.OnSubscribeConcatMap$ConcatMapSubscriber.onNext(OnSubscribeConcatMap.java:144)

at com.netflix.loadbalancer.reactive.LoadBalancerCommand$1.call(LoadBalancerCommand.java:185)

at com.netflix.loadbalancer.reactive.LoadBalancerCommand$1.call(LoadBalancerCommand.java:180)

at rx.Observable.unsafeSubscribe(Observable.java:10151)

at rx.internal.operators.OnSubscribeConcatMap.call(OnSubscribeConcatMap.java:94)

at rx.internal.operators.OnSubscribeConcatMap.call(OnSubscribeConcatMap.java:42)

at rx.Observable.unsafeSubscribe(Observable.java:10151)

at rx.internal.operators.OperatorRetryWithPredicate$SourceSubscriber$1.call(OperatorRetryWithPredicate.java:127)

at rx.internal.schedulers.TrampolineScheduler$InnerCurrentThreadScheduler.enqueue(TrampolineScheduler.java:73)

at rx.internal.schedulers.TrampolineScheduler$InnerCurrentThreadScheduler.schedule(TrampolineScheduler.java:52)

at rx.internal.operators.OperatorRetryWithPredicate$SourceSubscriber.onNext(OperatorRetryWithPredicate.java:79)

at rx.internal.operators.OperatorRetryWithPredicate$SourceSubscriber.onNext(OperatorRetryWithPredicate.java:45)

at rx.internal.util.ScalarSynchronousObservable$WeakSingleProducer.request(ScalarSynchronousObservable.java:276)

 

YASIR MEHMOOD's profile image
YASIR MEHMOOD

at rx.Subscriber.setProducer(Subscriber.java:209)

at rx.internal.util.ScalarSynchronousObservable$JustOnSubscribe.call(ScalarSynchronousObservable.java:138)

at rx.internal.util.ScalarSynchronousObservable$JustOnSubscribe.call(ScalarSynchronousObservable.java:129)

at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48)

at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30)

at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48)

at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30)

at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48)

at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30)

at rx.Observable.subscribe(Observable.java:10247)

at rx.Observable.subscribe(Observable.java:10214)

at rx.observables.BlockingObservable.blockForSingle(BlockingObservable.java:444)

at rx.observables.BlockingObservable.single(BlockingObservable.java:341)

at com.netflix.client.AbstractLoadBalancerAwareClient.executeWithLoadBalancer(AbstractLoadBalancerAwareClient.java:112)

at

YASIR MEHMOOD's profile image
YASIR MEHMOOD

org.springframework.cloud.netflix.feign.ribbon.LoadBalancerFeignClient.execute(LoadBalancerFeignClient.java:63)

at feign.SynchronousMethodHandler.executeAndDecode(SynchronousMethodHandler.java:97)

at feign.SynchronousMethodHandler.invoke(SynchronousMethodHandler.java:76)

at feign.ReflectiveFeign$FeignInvocationHandler.invoke(ReflectiveFeign.java:103)

at com.sun.proxy.$Proxy125.getDevice(Unknown Source)

at com.fedex.pulsar.push.service.PushService.retrieveFirebaseId(PushService.java:57)

at com.fedex.pulsar.push.service.PushService.handleRequest(PushService.java:39)

at com.fedex.pulsar.push.web.PushController.msgpush(PushController.java:28)

at sun.reflect.GeneratedMethodAccessor137.invoke(Unknown Source)

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.doPost(FrameworkServlet.java:872)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:661)

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.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:111)

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.doFilterInternal(FilterChainProxy.java:208)

at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:177)

at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:347)

at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:263)

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:109)

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.cloud.sleuth.instrument.web.TraceFilter.doFilter(TraceFilter.java:166)

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.springframework.boot.actuate.autoconfigure.MetricsFilter.doFilterInternal(MetricsFilter.java:106)

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.cloudfoundry.router.ClientCertificateMapper.doFilter(ClientCertificateMapper.java:77)

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:496)

at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:140)

at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:81)

at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:87)

at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:677)

at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:342)

at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:803)

at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)

at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:790)

at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1459)

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)

at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)

at java.lang.Thread.run(Thread.java:748) 

Caused by: javax.net.ssl.SSLHandshakeException : javax.net.ssl.SSLHandshakeException: Received fatal alert: bad_certificate

at at sun.security.ssl.Alerts.getSSLException(Alerts.java:192) 

at sun.security.ssl.Alerts.getSSLException(Alerts.java:154) 

at sun.security.ssl.SSLSocketImpl.recvAlert(SSLSocketImpl.java:2020) 

at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:1127) 

at sun.security.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1367) 

at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1395) 

at sun.security.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1379) 

at sun.net.www.protocol.https.HttpsClient.afterConnect(HttpsClient.java:559) 

at sun.net.www.protocol.https.AbstractDelegateHttpsURLConnection.connect(AbstractDelegateHttpsURLConnection.java:185) 

at sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1564) 

at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1492) 

at java.net.HttpURLConnection.getResponseCode(HttpURLConnection.java:480) ... 126 more

 

YASIR MEHMOOD's profile image
YASIR MEHMOOD

Do you know FedEx rep who has access to our platform and can look at as these problems are happening.

Daniel Lynch's profile image
Broadcom Employee Daniel Lynch

if this is related to the app identity certification?

https://docs.pivotal.io/pivotalcf/2-5/devguide/deploy-apps/instance-identity.html

 

the java build pack should have container security provider enabled which will automatically refresh the diego container identity certifications when they get updated. When push an app diego creates a temporary certification for the app container that rotates every day or so. ( not sure the exact interval )

 

 

make sure you have this enabled in your buildpack.

https://github.com/cloudfoundry/java-buildpack/blob/master/docs/framework-container_security_provider.md

Daniel Mikusa's profile image
Daniel Mikusa

Yes, I would agree. It sounds like your app may not be picking up the new application instance certificates after they have been rotated.

 

This should happen automatically for all apps using the Java buildpack. What version of the Java buildpack are you using, as I do recall at least one bug in this area.

YASIR MEHMOOD's profile image
YASIR MEHMOOD

java_next            2     true   false  java-buildpack-offline-v4.19.zip

 

Daniel Mikusa's profile image
Daniel Mikusa

If your app is using that version of the Java buildpack then you should be OK. JBP 4.19 is pretty recent and has the latest, at the time I write this, version of the container security provider components.

 

I would suggest you double check that the apps which are having issues are in fact using this version of the JBP, because it is possible for app authors to pick a different version of a buildpack. Also, make sure that the apps have been recently staged. You would need to restage an app so that it runs with the latest buildpack and produces a new droplet with the latest dependency software.

 

Aside from that, I would suggest the following:

  1. Capture the application logs (i.e. `cf logs`) from before the problem occurs through after the problem happens. This should provide a good view into what is going on.
  2. After the problem occurs, you'll want to check the container instance ID certs and make sure that they have actually been upgraded. Bad cert errors could happen if a.) the container instance id cert is updated, but your app does not use the new cert or b.) if the container instance id cert were not updated as it would be expired. It will help to know which of those two scenarios is occurring, since the cause would be different parts of CF.

 

You can look at `ls -l /etc/cf-instance-credentials/` inside the app container where the problem is happening. This will show the date the cert was last updated. If the date is within the last 24h then it should be current. You can also run this openssl command to actually look at the cert's validity period.

openssl x509 -in /etc/cf-instance-credentials/instance.crt -noout -text | grep -e 'Not Before' -e 'Not After' Not Before: May 16 16:01:51 2019 GMT Not After : May 17 16:01:51 2019 GMT

Once you've done all that, and assuming this is not just an issue with using an old buildpack, I would suggest opening a ticket with Pivotal Support. They will be able dig into the details more and debug this.

 

Instructions for opening a ticket: https://content.pivotal.io/support/support-quick-links-2

YASIR MEHMOOD's profile image
YASIR MEHMOOD

how do I specify caller and callee in above openssl command

 

Daniel Mikusa's profile image
Daniel Mikusa

That's not how the command works. It's not making network calls. It's pulling the cert info from the file referenced by the argument `-in`. That file will exist if you run the command inside an application container.

YASIR MEHMOOD's profile image
YASIR MEHMOOD

Assuming running cf run-task will create separate container - How can I run this command inside the app container ?

Daniel Mikusa's profile image
Daniel Mikusa

It would be easiest with an application. You could then just `cf ssh` into the application container. I'm not certain off hand if you can `cf ssh` into a task.

 

Are you only seeing this problem occur in a task? How long are your tasks running? Can you give a full example of the `cf run-task` command for one of the problem tasks?

YASIR MEHMOOD's profile image
YASIR MEHMOOD

ssh is not enabled for us

Error opening SSH connection: dial tcp ip:2222: getsockopt: connection refused

 

 

here is what I can do though

cf run-task app-abc "openssl s_client -connect app.xxx.xxx.xxx.com:443 < /dev/null"

 

Daniel Mikusa's profile image
Daniel Mikusa

>cf run-task app-abc "openssl s_client -connect app.xxx.xxx.xxx.com:443 < /dev/null"

 

This is not testing the right thing. This command is just looking at the certs on your API. That's not the issue here. The problem appears to be with your instance ID certs, which are injected into the container when it's created & updated every 24h.

 

What you might be able to do is `cf run-task app-abc "command"` and set the command to be something like this:

while [ 1 -eq 1 ]; do date; openssl x509 -noout -text -in /etc/cf-instance-credentials/instance.crt | grep -e 'Not Before' -e 'Not After'; sleep 5; done

That will repeatedly output the current date and the issue date of your instance id certs. It should run forever, so eventually you'll need to cancel that task, however let it run for longer than 24 hours first and see what happens. At some point, the cert should be rotated and you should see the issued dates change. If you instead see the current date continue past the "Not After" date, that would indicate the cert has expired and is not being updated.

 

Also, if you could confirm the following that would be helpful. Are you only seeing this problem occur in a task? How long are your tasks running where you see this problem? Can you give a full example of the `cf run-task` command for one of the problem tasks?

YASIR MEHMOOD's profile image
YASIR MEHMOOD

This problem is occurring in multiple foundations with multiple service and randomly - I will share more information as teams are digging more. One thing we were unclear and looking for help if possible - do you think if instance communication is through goRouter not directly c2c, these short lived cert will be in play, cause for goRouter we have long lived cert.

Daniel Mikusa's profile image
Daniel Mikusa

>One thing we were unclear and looking for help if possible - do you think if instance communication is through goRouter not directly c2c, these short lived cert will be in play, cause for goRouter we have long lived cert.

 

Unlikely. The issue you're describing is usually due to mutual TLS validation failing. By default, your Java applications because the Java buildpack configures them this way, will automatically attempt to use your application instance ID cert to perform mutual TLS authentication with the remote party. If the mutual TLS validation fails, that's where you end up seeing these `bad_certificate` errors.

 

It can happen for a couple of reasons:

  • If the instance ID cert has expired
  • If the remote party requires or performs mTLS validation, but does not trust the instance ID certs

 

The former is not very common and would only happen if there's a bug, because instance ID certs are automatically rotated by the platform and despite having a very short lifetime should be regenerated before they expire. The second option is quite common though.

 

If you have an app running on one CF Foundation talking to an app running on a second CF Foundation, they will not by default trust each other's certs. It can also happen if you terminate TLS at your load balancer and do not properly configure it to trust the application instance id certs.

 

If you don't care about mTLS validation, or if you want to temporarily disable for testing, then you can disable this behavior in the JBP by setting `key_manager_enabled` to `false`. Run `cf set-env <app> JBP_CONFIG_CONTAINER_SECURITY_PROVIDER '{key_manager_enabled: false}'`.

 

https://github.com/cloudfoundry/java-buildpack/blob/master/docs/framework-container_security_provider.md#configuration