Hybrid Connection Shows “Connected”, but AppService fails to Connect

Question

Hi,

I'm testing hybrid connections with app service connecting to an on-premise server endpoint by following these steps and also troubleshooting through this link. The hybrid connection is showing "Connected" on both HCM and in Azure portal but still the app is failing with "400 Bad request” error. From what I could see, the app service is able to connect to the on prem server(Microsoft Windows Server 2016 Standard) because I am able to see the errors in the event viewer but somehow the on-prem server is not able to get back to the app service. Looks like a firewall issue but as far as I understand with hybrid connections we don't need any firewall configuration. I also tweaked Microsoft.HybridConnectionManager.Listener.exe config file to enable the logs on the on-prem server where I installed the HCM and found the log trace (as shown below )under C:\Temp\ System.Net.trace immediate after restarting the HCM service.

DateTime=2021-02-24T00:01:42.2743280Z
System.Net Information: 0 : [4524] RAS supported: True
ProcessId=6940
DateTime=2021-02-24T00:01:42.5087118Z
System.Net Verbose: 0 : [4524] Entering HttpWebRequest#31665793::HttpWebRequest(https://api-hybrid-conn.servicebus.windows.net/api-hybrid-conn?api-version=2016-07#-1472137451)
ProcessId=6940
DateTime=2021-02-24T00:01:42.5868393Z
System.Net Verbose: 0 : [4524] Exiting HttpWebRequest#31665793::HttpWebRequest()
ProcessId=6940
DateTime=2021-02-24T00:01:42.5868393Z
System.Net Verbose: 0 : [4524] Entering HttpWebRequest#31665793::HttpWebRequest(uri: 'https://api-hybrid-conn.servicebus.windows.net/api-hybrid-conn?api-version=2016-07', connectionGroupName: '6385742')
ProcessId=6940
DateTime=2021-02-24T00:01:42.5868393Z
System.Net Verbose: 0 : [4524] Exiting HttpWebRequest#31665793::HttpWebRequest()
ProcessId=6940
DateTime=2021-02-24T00:01:42.5868393Z
System.Net Verbose: 0 : [1940] Entering HttpWebRequest#31665793::BeginGetResponse()
ProcessId=6940
DateTime=2021-02-24T00:01:42.6024625Z
System.Net Error: 0 : [1940] Can't retrieve proxy settings for Uri 'https://api-hybrid-conn.servicebus.windows.net/api-hybrid-conn?api-version=2016-07'. Error code: 12180.
ProcessId=6940
DateTime=2021-02-24T00:01:42.6024625Z
System.Net Verbose: 0 : [1940] Entering ServicePoint#35320229::ServicePoint(api-hybrid-conn.servicebus.windows.net:443)
ProcessId=6940
DateTime=2021-02-24T00:01:42.6024625Z
System.Net Information: 0 : [1940] Associating HttpWebRequest#31665793 with ServicePoint#35320229
ProcessId=6940
DateTime=2021-02-24T00:01:42.6024625Z
System.Net Information: 0 : [1940] Associating Connection#17653682 with HttpWebRequest#31665793
ProcessId=6940
DateTime=2021-02-24T00:01:42.6024625Z
System.Net.Sockets Verbose: 0 : [1940] Entering Socket#42194754::Socket(AddressFamily#2)
ProcessId=6940
DateTime=2021-02-24T00:01:42.6024625Z
System.Net.Sockets Verbose: 0 : [1940] Exiting Socket#42194754::Socket()
ProcessId=6940
DateTime=2021-02-24T00:01:42.6024625Z
System.Net.Sockets Verbose: 0 : [1940] Entering Socket#15688314::Socket(AddressFamily#23)
ProcessId=6940
DateTime=2021-02-24T00:01:42.6024625Z
System.Net.Sockets Verbose: 0 : [1940] Exiting Socket#15688314::Socket()
ProcessId=6940
DateTime=2021-02-24T00:01:42.6024625Z
System.Net.Sockets Verbose: 0 : [1940] Entering DNS::TryInternalResolve(api-hybrid-conn.servicebus.windows.net)
ProcessId=6940
DateTime=2021-02-24T00:01:42.6024625Z
System.Net.Sockets Verbose: 0 : [1940] Entering Socket#42194754::BeginConnectEx()
ProcessId=6940
DateTime=2021-02-24T00:01:42.6181079Z
System.Net.Sockets Verbose: 0 : [1940] Entering Socket#42194754::InternalBind(0.0.0.0:0#0)
ProcessId=6940
DateTime=2021-02-24T00:01:42.6181079Z
System.Net.Sockets Verbose: 0 : [1940] Exiting Socket#42194754::InternalBind()
ProcessId=6940
DateTime=2021-02-24T00:01:42.6181079Z
System.Net.Sockets Verbose: 0 : [1940] Exiting Socket#42194754::BeginConnectEx() -> ConnectOverlappedAsyncResult#52307948
ProcessId=6940
DateTime=2021-02-24T00:01:42.6181079Z
System.Net Verbose: 0 : [1940] Exiting HttpWebRequest#31665793::BeginGetResponse() -> ContextAwareResult#40535505
ProcessId=6940
DateTime=2021-02-24T00:01:42.6181079Z
System.Net.Sockets Verbose: 0 : [3288] Entering Socket#42194754::EndConnect(ConnectOverlappedAsyncResult#52307948)
ProcessId=6940
DateTime=2021-02-24T00:01:42.7276415Z
System.Net.Sockets Verbose: 0 : [3288] Entering Socket#42194754::InternalEndConnect(ConnectOverlappedAsyncResult#52307948)
ProcessId=6940
DateTime=2021-02-24T00:01:42.7276415Z
System.Net.Sockets Information: 0 : [3288] Socket#42194754 - Created connection from 10.229.0.1:56127 to 40.86.102.100:443.
ProcessId=6940
DateTime=2021-02-24T00:01:42.7430355Z
System.Net.Sockets Verbose: 0 : [3288] Exiting Socket#42194754::InternalEndConnect()
ProcessId=6940
DateTime=2021-02-24T00:01:42.7430355Z
System.Net.Sockets Verbose: 0 : [3288] Exiting Socket#42194754::EndConnect()

DateTime=2021-02-24T00:01:43.1548212Z
System.Net Verbose: 0 : [3288] Exiting ConnectStream#48611003::Close()
ProcessId=6940
DateTime=2021-02-24T00:01:43.1548212Z
System.Net Verbose: 0 : [3288] Entering HttpWebRequest#31665793::Abort()
ProcessId=6940
DateTime=2021-02-24T00:01:43.1860749Z
System.Net Error: 0 : [3288] Exception in HttpWebRequest#31665793:: - The request was aborted: The request was canceled..
ProcessId=6940
DateTime=2021-02-24T00:01:43.1860749Z
System.Net Verbose: 0 : [3288] Exiting HttpWebRequest#31665793::Abort()
ProcessId=6940
DateTime=2021-02-24T00:01:43.1860749Z
System.Net Information: 0 : [3288] ServicePoint#35320229::CloseConnectionGroupInternal(6385742)
ProcessId=6940
DateTime=2021-02-24T00:01:43.1860749Z
System.Net Information: 0 : [3288] ServicePoint#35320229::CloseConnectionGroupHelper(connectionGroupName=6385742, closeInternal=True

Also, The tcpping and telnet(tried from linux box) tests are very misleading since it’s handshaking the Azure-end of the Hybrid Connection, not the actual on-prem application's TCP endpoint.

Hence, I started testing at the application layer by running a curl request from the Kudu console to the on-prem hybrid connection endpoint by running curl -vk https://api-hybrid-endpoint:port -I and got curl response HTTP/2 400 from the on-prem server(please find below curl_request for the detailed 400 response).

D:\home> % Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* Trying 127.0.0.170:CustomPort...
* Connected to HYBRIDENDPOINT (127.0.0.170) port CustomPort (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
* CAfile: D:/Program Files/Git/mingw64/ssl/certs/ca-bundle.crt
CApath: none
} [5 bytes data]
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* TLSv1.3 (IN), TLS handshake, Server hello (2):
{ [94 bytes data]
* TLSv1.2 (IN), TLS handshake, Certificate (11):
{ [740 bytes data]
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
{ [300 bytes data]
* TLSv1.2 (IN), TLS handshake, Server finished (14):
{ [4 bytes data]
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
} [37 bytes data]
* TLSv1.2 (OUT), TLS change cipher, Change cipher spec (1):
} [1 bytes data]
* TLSv1.2 (OUT), TLS handshake, Finished (20):
} [16 bytes data]
* TLSv1.2 (IN), TLS handshake, Finished (20):
{ [16 bytes data]
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server accepted to use h2
* Server certificate:
* subject: CN=HYBRIDENDPOINT
* start date: Jan 3 06:49:29 2020 GMT
* expire date: Jan 3 00:00:00 2021 GMT
* issuer: CN=HYBRIDENDPOINT
* SSL certificate verify result: unable to get local issuer certificate (20), continuing anyway.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
} [5 bytes data]
* Using Stream ID: 1 (easy handle 0x940770)
} [5 bytes data]

HEAD / HTTP/2

Host: HYBRIDENDPOINT:CustomPort

user-agent: curl/7.71.1

accept: /

{ [5 bytes data]
* Connection state changed (MAX_CONCURRENT_STREAMS == 100)!
} [5 bytes data]
< HTTP/2 400

< content-length: 334

< content-type: text/html; charset=us-ascii

< server: Microsoft-HTTPAPI/2.0

< date: Wed, 24 Feb 2021 00:16:41 GMT

<

0 334 0 0 0 0 0 0 --:--:-- 0:00:01 --:--:-- 0HTTP/2 400
content-length: 334
content-type: text/html; charset=us-ascii
server: Microsoft-HTTPAPI/2.0
date: Wed, 24 Feb 2021 00:16:41 GMT

• Connection #0 to host HYBRIDENDPOINT left intact
• List item

I am not sure what else might be blocking the connection at this point. Appreciate if you can provide an on-call or offline support and help debug this issue.

PS: I’ve also made below changes on the on-prem side to get the hybrid connection working but no luck

1. Allowed Outbound Connections on port 443(Ran Test-NetConnection -computer <hybrid-conn>.servicebus.windows.net -Port 443 and got a success response for the TcpTest)
2. Whitelisted the Service Bus URL’s/Gateways in the outbound rules
3. Enabled TLS1.2/1.3 on the on-prem server for both server and client by following this link

Thanks,
Kishore

Answer 1

Hi @krishnakishore.durgasi . Were you able to resolve the issue? I am also facing similar issue.