Exception while creating a VMware on AWS cloud account in vRealize Automation

Updated: Apr 24


Recently was working on an vRealize Automation environment 8.x version ( vCF based ) where an authenticated proxy was involved for external connectivity.


We were trying to add an VMware Cloud on AWS cloud account and it was failing with the below error




Looking into provisioning-service-app.log , we see the actual error



2021-10-05T04:06:51.975Z [priority='INFO' thread='reactor-http-epoll-13' user='' org='' context='' parent='' token=''] com.vmware.xenon.common.SpringHostUtils.responseEntityToOperation:901 - [POST https://console. cloud.vmware.com/csp/gateway/am/api/auth/api-tokens/authorize] Exception received with no ClientResponse: java.util.concurrent.CompletionException: javax.net.ssl.SSLException: failure when writing TLS control frames

The whole exceptions is as below



2021-10-05T04:06:51.726Z [priority='INFO' thread='reactor-http-epoll-15' user='arun' org='ce3fdd9b-f3f1-41f1-8622-7cb1e53fae71' context='f9899447-69e3-4843-bae0-303ace93b1e4' parent='' token='c2559493-fae 5-4faf-ba28-7f1fddcb58dc'] com.vmware.xenon.common.SpringHostUtils.sendRequest:233 - Sending POST http://10.244.10.110:8282/provisioning/mgmt/vmc-sddc (referer http://10.244.10.110:8282/provisioning/uerp) as a remote request to change auth context 
2021-10-05T04:06:51.975Z [priority='INFO' thread='reactor-http-epoll-13' user='' org='' context='' parent='' token=''] com.vmware.xenon.common.SpringHostUtils.responseEntityToOperation:901 - [POST https://console. cloud.vmware.com/csp/gateway/am/api/auth/api-tokens/authorize] Exception received with no ClientResponse: java.util.concurrent.CompletionException: javax.net.ssl.SSLException: failure when writing TLS control frames 
                at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331) 
                at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:346) 
                at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1063) 
                at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) 
                at java.base/java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088) 
                at reactor.core.publisher.MonoToCompletableFuture.onError(MonoToCompletableFuture.java:76) 
                at io.opentracing.contrib.reactor.TracedSubscriber.onError(TracedSubscriber.java:79) 
                at reactor.core.publisher.SerializedSubscriber.onError(SerializedSubscriber.java:124) 
*
*
* 
                at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901) 
                at io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:818) 
                at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) 
                at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) 
                at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384) 
                at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) 
                at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) 
                at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) 
                at java.base/java.lang.Thread.run(Thread.java:834) 
        Caused by: javax.net.ssl.SSLException: failure when writing TLS control frames 
                at io.netty.handler.ssl.SslHandler.setHandshakeFailureTransportFailure(SslHandler.java:1855) 
                Suppressed: reactor.core.publisher.FluxOnAssembly$OnAssemblyException: 
        Error has been observed at the following site(s): 
                |_ checkpoint ⇢ Request to POST https://console.cloud.vmware.com/csp/gateway/am/api/auth/api-tokens/authorize [DefaultWebClient] 
        Stack trace: 
                        at io.netty.handler.ssl.SslHandler.setHandshakeFailureTransportFailure(SslHandler.java:1855) 
                        at io.netty.handler.ssl.SslHandler.access$600(SslHandler.java:167) 
                        at io.netty.handler.ssl.SslHandler$2.operationComplete(SslHandler.java:970) 
                        at io.netty.handler.ssl.SslHandler$2.operationComplete(SslHandler.java:965) 
                        at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:577) 
                        at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:551) 
                        at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:490) 
                        at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:615)*
*
*
* 
                        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384) 
                        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) 
                        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) 
                        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) 
                        at java.base/java.lang.Thread.run(Thread.java:834) 
        Caused by: io.netty.handler.proxy.ProxyConnectException: http, none, proxy-service.prelude.svc.cluster.local/10.244.14.224:3128 => console.cloud.vmware.com:443, disconnected 
                at io.netty.handler.proxy.ProxyHandler.channelInactive(ProxyHandler.java:234) 
                at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) 


*
*
                at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901) 
                at io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:818) 
                at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) 
                at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) 
                at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384) 
                at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) 
                at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) 
                at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) 
                at java.base/java.lang.Thread.run(Thread.java:834)



When this error occurs we see following statements under proxy-service-xxxxx/squid-proxy.log


1633406811.973 epoch timestamp relates to the timestamp when the error occurred in the UI.

1633406811.973 --> 2021-10-05T04:06:51


1633406811.973    240 10.244.0.110 TCP_TUNNEL/407 293 CONNECT console.cloud.vmware.com:443 - FIRSTUP_PARENT/59.154.134.108 -

Inspecting older squid-proxy logs, whenever an attempt to add a new VMC vCenter cloud account was done , we did see this statement




proxy-service/squid-proxy.log-202110020000.xz_extracted/squid-proxy.log-202110020000:1633063657.998    108 10.244.10.110 TCP_TUNNEL/407 293 CONNECT console.cloud.vmware.com:443 - FIRSTUP_PARENT/59.154.134.108 - 

proxy-service/squid-proxy.log:1633406811.973    240 10.244.10.110 TCP_TUNNEL/407 293 CONNECT console.cloud.vmware.com:443 - FIRSTUP_PARENT/59.154.134.108 - 

proxy-service/squid-proxy.log-202110010000.xz_extracted/squid-proxy.log-202110010000:1633008305.662    980 10.244.10.110 TCP_TUNNEL/407 293 CONNECT console.cloud.vmware.com:443 - FIRSTUP_PARENT/59.154.134.108 - 

proxy-service/squid-proxy.log-202110010000.xz_extracted/squid-proxy.log-202110010000:1633008582.091   1413 10.244.10.110 TCP_TUNNEL/407 293 CONNECT console.cloud.vmware.com:443 - FIRSTUP_PARENT/59.154.134.108 - 

proxy-service/squid-proxy.log-202110010000.xz_extracted/squid-proxy.log-202110010000:1633008851.485   2341 10.244.10.110 TCP_TUNNEL/407 287 CONNECT console.cloud.vmware.com:443 - FIRSTUP_PARENT/59.154.134.109 - 

proxy-service/squid-proxy.log-202110010000.xz_extracted/squid-proxy.log-202110010000:1633008862.656     24 10.244.10.110 TCP_TUNNEL/407 287 CONNECT console.cloud.vmware.com:443 - FIRSTUP_PARENT/59.154.134.109 -


Let's understand this squid-proxy statement in depth once



1633406811.973

The client request time stamp in Squid format

240

​The time the proxy spent processing the client request; the number of milliseconds between the time that the client established the connection with the proxy and the time that the proxy sent the last byte of the response back to the client.

10.244.0.110

The IP address of the client's host machine. In our case it's the provisioning-service-app

TCP_TUNNEL/407

​ Cache Result Code. How the cache responded to the request. The proxy response status code from the content gateway to the client

293

The length of the content gateway

CONNECT

​The client request method: GET, POST, and so on

​ Canonical URL

​-

The authenticated client's user name. A hyphen (-) means that no authentication was required

FIRSTUP_PARENT/59.154.134.108 -

​The proxy hierarchy route; the route Content Gateway used to retrieve the object. The proxy request server name; the name of the server that fulfilled the request. If the request was a cache hit, this field contains a hyphen (-).


As we can see all of the result codes are TCP_TUNNEL/407. What do we understand by this based on the search on google


The HTTP 407 Proxy Authentication Required client error status response code indicates that the request has not been applied because it lacks valid authentication credentials for a proxy server that is between the browser and the server that can access the requested resource.


The vracli proxy show output on the node was as below



root@node02[ ~ ]# vracli proxy show 
{ 
    "enabled": true, 
    "host": "proxy-service.prelude.svc.cluster.local", 
    "java-proxy-exclude": ********", 
    "java-user": "arun@nc.com", 
    "password": null, 
    "port": 3128, 
    "proxy-exclude": "************", 
    "scheme": "http", 
    "upstream_proxy_host": "******.lb.service.dev", 
    "upstream_proxy_password_encoded": "*CENSORED*", 
    "upstream_proxy_port": 80, 
    "upstream_proxy_user_encoded": "arun%40nc.com", 
    "user": null, 
    "internal.proxy.config": "*******", 
    "internal.proxy.config.type": "non-default" 
}


After we reached this point , one of our peer pointed out that he did recently face an issue where if the java_user is set to UPN and not just a USERNAME , then TCP_TUNNEL/407 will occur


So based on this we decided to reconfigure the proxy which has been already set


root@node02[ ~ ]# vracli proxy show 
{ 
    "enabled": true, 
    "host": "proxy-service.prelude.svc.cluster.local", 
    "java-proxy-exclude": ********", 
    "java-user": "arun", 
    "password": null, 
    "port": 3128, 
    "proxy-exclude": "************", 
    "scheme": "http", 
    "upstream_proxy_host": "******.lb.service.dev", 
    "upstream_proxy_password_encoded": "*CENSORED*", 
    "upstream_proxy_port": 80, 
    "upstream_proxy_user_encoded": "arun", 
    "user": null, 
    "internal.proxy.config": "*******", 
    "internal.proxy.config.type": "non-default" 
}

Once we made the change , we were able to validate the API and there were no exceptions


I will try and gather the reason behind why it does not work with UPN and works with USERNAME and update it here.



Yea , if you have a proxy configured and adding a VMware Cloud on AWS endpoint keep this in mind

173 views0 comments