[BUG] 407 Proxy Authentication Required should not trigger warning log

[nandorsoma]

Describe the bug
When we attempt to connect to a container through a proxy which requires authentication, initially the library tries to connect without authentication and then if it's needed a com.azure.core.util.AuthorizationChallengeHandler will do the authentication. The problem is that even in a successful login flow, between the first failed request and the authentication challenge handling reactor.netty.http.client.HttpClientConnect logs a warning message that it failed to connect to a proxy. This is misleading in that situation because it is part of the normal flow and doesn't necessarily mean that the authentication is failed or will fail.

This happens because in HttpProxy:handleResponse an exception is thrown, even if the challenge handling started by setting value to proxyChallengeHolderReference.

Exception or Stack Trace

[reactor-http-kqueue-2] WARN reactor.netty.http.client.HttpClientConnect - [d0f24979, L:/127.0.0.1:52841 - R:localhost/127.0.0.1:9080] The connection observed an error
javax.net.ssl.SSLException: failure when writing TLS control frames
	at io.netty.handler.ssl.SslHandler.setHandshakeFailureTransportFailure(SslHandler.java:1896)
	at io.netty.handler.ssl.SslHandler.access$600(SslHandler.java:168)
	at io.netty.handler.ssl.SslHandler$2.operationComplete(SslHandler.java:933)
	at io.netty.handler.ssl.SslHandler$2.operationComplete(SslHandler.java:928)
	at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:578)
	at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:552)
	at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:491)
	at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:616)
	at io.netty.util.concurrent.DefaultPromise.setFailure0(DefaultPromise.java:609)
	at io.netty.util.concurrent.DefaultPromise.tryFailure(DefaultPromise.java:117)
	at io.netty.channel.PendingWriteQueue.safeFail(PendingWriteQueue.java:288)
	at io.netty.channel.PendingWriteQueue.removeAndFailAll(PendingWriteQueue.java:186)
	at io.netty.handler.proxy.ProxyHandler.failPendingWrites(ProxyHandler.java:434)
	at io.netty.handler.proxy.ProxyHandler.failPendingWritesAndClose(ProxyHandler.java:351)
	at io.netty.handler.proxy.ProxyHandler.setConnectFailure(ProxyHandler.java:346)
	at io.netty.handler.proxy.ProxyHandler.channelRead(ProxyHandler.java:266)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:327)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:299)
	at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.kqueue.AbstractKQueueStreamChannel$KQueueStreamUnsafe.readReady(AbstractKQueueStreamChannel.java:544)
	at io.netty.channel.kqueue.AbstractKQueueChannel$AbstractKQueueUnsafe.readReady(AbstractKQueueChannel.java:383)
	at io.netty.channel.kqueue.KQueueEventLoop.processReady(KQueueEventLoop.java:211)
	at io.netty.channel.kqueue.KQueueEventLoop.run(KQueueEventLoop.java:289)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:995)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:750)
Caused by: io.netty.handler.proxy.HttpProxyHandler$HttpProxyConnectException: Failed to connect to proxy. Status: 407 Proxy Authentication Required
	at com.azure.core.http.netty.implementation.HttpProxyHandler.handleResponse(HttpProxyHandler.java:242)
	at io.netty.handler.proxy.ProxyHandler.channelRead(ProxyHandler.java:257)
	... 22 more

To Reproduce
https://github.com/nandorsoma/azure-blob-proxy-warning-example

Code Snippet

azure-sdk-for-java/sdk/core/azure-core-http-netty/src/main/java/com/azure/core/http/netty/implementation/HttpProxyHandler.java

Line 208 in 457609b

protected boolean handleResponse(ChannelHandlerContext ctx, Object o) throws ProxyConnectException {

Expected behavior
WARNING log should not be logged for the first authentication challenge.

Screenshots
If applicable, add screenshots to help explain your problem.

Setup (please complete the following information):

• OS: MacOS
• IDE: IntelliJ
• Library/Libraries: com.azure:azure-storage-blob:12.18.0
• Java version: 8
• App Server/Environment:
• Frameworks:

If you suspect a dependency version mismatch (e.g. you see NoClassDefFoundError, NoSuchMethodError or similar), please check out Troubleshoot dependency version conflict article first. If it doesn't provide solution for the problem, please provide:

• verbose dependency tree (mvn dependency:tree -Dverbose)
• exception message, full stack trace, and any available logs

Additional context
Add any other context about the problem here.

Information Checklist
Kindly make sure that you have added all the following information above and checkoff the required fields otherwise we will treat the issuer as an incomplete report

• Bug Description Added
• Repro Steps Added
• Setup information Added

[joshfree]

Hi @nandorsoma thank you for filing this detailed GitHub issue. @alzimmermsft could you please follow up?

[nandorsoma]

Thanks for the fix!