Request to forwarded port doesn't finish after response was recieved

[szilvesztercsab]

trafficstars

Hi, awesome product!

Just have a slight glitch.

So, I'm using code-tunnel.service on a Debian GNU/Linux 12 box in my home and I connect via the browser to it.

All goes well and ports are forwarded correctly, however I can't figure out why all requests sent to the forwarded port seem to succeed first and fail later.

Let me try to explain and demonstrate:

echo '<?= "Hello World!" ?>' > index.php
php -S 0.0.0.0:8888

The above opens up port 8888 and forwards it to: https://<some-random-chars>-8888.euw.devtunnels.ms.

I visit the link and see the request being resolved to a status of 200 instantly, and the response contains the expected content. But the browser is still loading the page.

Then a minute or so later, the same request that earlier responded with a 200, is now being reported as (failed)net::ERR_HTTP2_PROTOCOL_ERROR.

The request timings look like so:

This happens with all requests on any browser (even in incognito - after I login ofcourse), on VSCode insiders version too, and the request always takes exactly 1 minute.

The logs while this is happing look like so (I omitted some russh::client::encrypted and russh::server::kex entries below):

Feb 21 17:48:23 szbcs code[729]: [2025-02-21 17:48:23] info [tunnels::connections::relay_tunnel_host] Opened new client on channel 36
Feb 21 17:48:23 szbcs code[729]: [2025-02-21 17:48:23] debug [tunnels::connections::relay_tunnel_host] starting to serve host relay client session
Feb 21 17:48:23 szbcs code[729]: [2025-02-21 17:48:23] info [russh::server] wrote id
Feb 21 17:48:23 szbcs code[729]: [2025-02-21 17:48:23] debug [russh::ssh_read] read_ssh_id: reading
Feb 21 17:48:23 szbcs code[729]: [2025-02-21 17:48:23] debug [russh::ssh_read] read 39
Feb 21 17:48:23 szbcs code[729]: [2025-02-21 17:48:23] debug [russh::ssh_read] Ok("SSH-2.0-Microsoft.DevTunnels.Ssh_3.12\r\n")
Feb 21 17:48:23 szbcs code[729]: [2025-02-21 17:48:23] info [russh::server] read other id
Feb 21 17:48:23 szbcs code[729]: [2025-02-21 17:48:23] info [russh::server] session is running
Feb 21 17:48:24 szbcs code[729]: [2025-02-21 17:48:23] debug [russh::ssh_read] id 39 39
Feb 21 17:48:24 szbcs code[729]: [2025-02-21 17:48:24] debug [russh::client::encrypted] channel_window_adjust
Feb 21 17:48:24 szbcs code[729]: [2025-02-21 17:48:24] debug [russh::client::encrypted] amount: 4194326
Feb 21 17:48:24 szbcs code[729]: [2025-02-21 17:48:24] debug [russh::server::encrypted] request: Ok("ssh-userauth")
Feb 21 17:48:24 szbcs code[729]: [2025-02-21 17:48:24] debug [russh::server::encrypted] name: "tunnel" Ok("ssh-connection") Ok("none")
Feb 21 17:48:24 szbcs code[729]: [2025-02-21 17:48:24] debug [tunnels::connections::relay_tunnel_host] host relay client session successfully authed
Feb 21 17:48:24 szbcs code[729]: [2025-02-21 17:48:24] debug [tunnels::connections::relay_tunnel_host] Forwarded connection to port 8888
Feb 21 17:48:24 szbcs code[729]: [2025-02-21 17:48:24] debug [tunnels::connections::relay_tunnel_host] EOF from TCP stream, ending
Feb 21 17:49:13 szbcs code[729]: [2025-02-21 17:49:13] debug [tunnels::connections::ws] received liveness pong
Feb 21 17:49:23 szbcs code[729]: [2025-02-21 17:49:23] debug [russh::client::encrypted] channel_close
Feb 21 17:49:23 szbcs code[729]: [2025-02-21 17:49:23] debug [russh::server::encrypted] handler.channel_close ChannelId(2)
Feb 21 17:49:23 szbcs code[729]: [2025-02-21 17:49:23] debug [russh::server::session] break
Feb 21 17:49:23 szbcs code[729]: [2025-02-21 17:49:23] debug [russh::server::session] disconnected

• EOF from TCP stream, ending is when I recieve the 200 status code.
• disconnected is when the same request turns into a (failed)net::ERR_HTTP2_PROTOCOL_ERROR

This is surely not expected behaviour, is it? Any help on the matter would be greatly appreciated.

[szilvesztercsab]

The same with curl:

❯ curl -v https://n157cptv-8888.euw.devtunnels.ms/
* Host n157cptv-8888.euw.devtunnels.ms:443 was resolved.
* IPv6: (none)
* IPv4: 20.103.221.187
*   Trying 20.103.221.187:443...
* Connected to n157cptv-8888.euw.devtunnels.ms (20.103.221.187) port 443
* ALPN: curl offers h2,http/1.1
* (304) (OUT), TLS handshake, Client hello (1):
*  CAfile: /etc/ssl/cert.pem
*  CApath: none
* (304) (IN), TLS handshake, Server hello (2):
* (304) (IN), TLS handshake, Unknown (8):
* (304) (IN), TLS handshake, Certificate (11):
* (304) (IN), TLS handshake, CERT verify (15):
* (304) (IN), TLS handshake, Finished (20):
* (304) (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / AEAD-AES256-GCM-SHA384 / [blank] / UNDEF
* ALPN: server accepted h2
* Server certificate:
*  subject: C=US; ST=WA; L=Redmond; O=Microsoft Corporation; CN=devtunnels.ms
*  start date: Feb  9 04:35:05 2025 GMT
*  expire date: Aug  8 04:35:05 2025 GMT
*  subjectAltName: host "n157cptv-8888.euw.devtunnels.ms" matched cert's "*.euw.devtunnels.ms"
*  issuer: C=US; O=Microsoft Corporation; CN=Microsoft Azure RSA TLS Issuing CA 07
*  SSL certificate verify ok.
* using HTTP/2
* [HTTP/2] [1] OPENED stream for https://n157cptv-8888.euw.devtunnels.ms/
* [HTTP/2] [1] [:method: GET]
* [HTTP/2] [1] [:scheme: https]
* [HTTP/2] [1] [:authority: n157cptv-8888.euw.devtunnels.ms]
* [HTTP/2] [1] [:path: /]
* [HTTP/2] [1] [user-agent: curl/8.7.1]
* [HTTP/2] [1] [accept: */*]
> GET / HTTP/2
> Host: n157cptv-8888.euw.devtunnels.ms
> User-Agent: curl/8.7.1
> Accept: */*
>
* Request completely sent off
< HTTP/2 200
< date: Fri, 21 Feb 2025 16:03:04 GMT
< content-type: text/html; charset=UTF-8
< cache-control: no-cache,no-store
< expires: Thu, 01 Jan 1970 00:00:00 GMT
< pragma: no-cache
< set-cookie: ...
< x-content-type-options: nosniff
< ratelimit-limit: HttpRequestRatePerPort:1500/m
< ratelimit-limit: ClientConnectionsPerPort: max 1000
< ratelimit-remaining: HttpRequestRatePerPort:1498
< ratelimit-remaining: ClientConnectionsPerPort:999
< ratelimit-reset: HttpRequestRatePerPort:3s
< x-report-abuse: https://msrc.microsoft.com/report/abuse
< x-ms-ratelimit-limit: 1500
< x-ms-ratelimit-remaining: 1497
< x-ms-ratelimit-used: 3
< x-ms-ratelimit-reset: 0
< host: localhost:8888
< x-powered-by: PHP/8.2.26
< x-robots-tag: noindex, nofollow
< referrer-policy: same-origin
< vssaas-request-id: d3b50fa8-65ce-4f52-a197-5ba8ed55658f
< strict-transport-security: max-age=31536000; includeSubDomains
< x-served-by: tunnels-prod-rel-euw-v3-cluster
<
* HTTP/2 stream 1 was not closed cleanly: INTERNAL_ERROR (err 2)
* Connection #0 to host n157cptv-8888.euw.devtunnels.ms left intact
curl: (92) HTTP/2 stream 1 was not closed cleanly: INTERNAL_ERROR (err 2)
Hello World!%

[szilvesztercsab]

The same with curl --http1.1:

❯ curl -v --http1.1 https://n157cptv-8888.euw.devtunnels.ms/
* Host n157cptv-8888.euw.devtunnels.ms:443 was resolved.
* IPv6: (none)
* IPv4: 20.103.221.187
*   Trying 20.103.221.187:443...
* Connected to n157cptv-8888.euw.devtunnels.ms (20.103.221.187) port 443
* ALPN: curl offers http/1.1
* (304) (OUT), TLS handshake, Client hello (1):
*  CAfile: /etc/ssl/cert.pem
*  CApath: none
* (304) (IN), TLS handshake, Server hello (2):
* (304) (IN), TLS handshake, Unknown (8):
* (304) (IN), TLS handshake, Certificate (11):
* (304) (IN), TLS handshake, CERT verify (15):
* (304) (IN), TLS handshake, Finished (20):
* (304) (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / AEAD-AES256-GCM-SHA384 / [blank] / UNDEF
* ALPN: server accepted http/1.1
* Server certificate:
*  subject: C=US; ST=WA; L=Redmond; O=Microsoft Corporation; CN=devtunnels.ms
*  start date: Feb  9 04:35:05 2025 GMT
*  expire date: Aug  8 04:35:05 2025 GMT
*  subjectAltName: host "n157cptv-8888.euw.devtunnels.ms" matched cert's "*.euw.devtunnels.ms"
*  issuer: C=US; O=Microsoft Corporation; CN=Microsoft Azure RSA TLS Issuing CA 07
*  SSL certificate verify ok.
* using HTTP/1.x
> GET / HTTP/1.1
> Host: n157cptv-8888.euw.devtunnels.ms
> User-Agent: curl/8.7.1
> Accept: */*
>
* Request completely sent off
< HTTP/1.1 200 OK
< Date: Fri, 21 Feb 2025 16:04:09 GMT
< Content-Type: text/html; charset=UTF-8
< Transfer-Encoding: chunked
< Connection: keep-alive
< Cache-Control: no-cache,no-store
< Expires: Thu, 01 Jan 1970 00:00:00 GMT
< Pragma: no-cache
< Set-Cookie: ...
< X-Content-Type-Options: nosniff
< RateLimit-Limit: HttpRequestRatePerPort:1500/m
< RateLimit-Remaining: HttpRequestRatePerPort:1499
< RateLimit-Reset: HttpRequestRatePerPort:4s
< X-Report-Abuse: https://msrc.microsoft.com/report/abuse
< x-ms-ratelimit-limit: 1500
< x-ms-ratelimit-remaining: 1496
< x-ms-ratelimit-used: 4
< x-ms-ratelimit-reset: 0
< Host: localhost:8888
< X-Powered-By: PHP/8.2.26
< X-Robots-Tag: noindex, nofollow
< Referrer-Policy: same-origin
< VsSaaS-Request-Id: b8f81c7e-66b7-4aa2-8764-4972d1124ff2
< Strict-Transport-Security: max-age=31536000; includeSubDomains
< X-Served-By: tunnels-prod-rel-euw-v3-cluster
<
* transfer closed with outstanding read data remaining
* Closing connection
curl: (18) transfer closed with outstanding read data remaining
Hello World!%

[szilvesztercsab]

And with curl --http1.0:

❯ curl -v --http1.0 https://n157cptv-8888.euw.devtunnels.ms/
* Host n157cptv-8888.euw.devtunnels.ms:443 was resolved.
* IPv6: (none)
* IPv4: 20.103.221.187
*   Trying 20.103.221.187:443...
* Connected to n157cptv-8888.euw.devtunnels.ms (20.103.221.187) port 443
* ALPN: curl offers http/1.1
* (304) (OUT), TLS handshake, Client hello (1):
*  CAfile: /etc/ssl/cert.pem
*  CApath: none
* (304) (IN), TLS handshake, Server hello (2):
* (304) (IN), TLS handshake, Unknown (8):
* (304) (IN), TLS handshake, Certificate (11):
* (304) (IN), TLS handshake, CERT verify (15):
* (304) (IN), TLS handshake, Finished (20):
* (304) (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / AEAD-AES256-GCM-SHA384 / [blank] / UNDEF
* ALPN: server accepted http/1.1
* Server certificate:
*  subject: C=US; ST=WA; L=Redmond; O=Microsoft Corporation; CN=devtunnels.ms
*  start date: Feb  9 04:35:05 2025 GMT
*  expire date: Aug  8 04:35:05 2025 GMT
*  subjectAltName: host "n157cptv-8888.euw.devtunnels.ms" matched cert's "*.euw.devtunnels.ms"
*  issuer: C=US; O=Microsoft Corporation; CN=Microsoft Azure RSA TLS Issuing CA 07
*  SSL certificate verify ok.
* using HTTP/1.x
> GET / HTTP/1.0
> Host: n157cptv-8888.euw.devtunnels.ms
> User-Agent: curl/8.7.1
> Accept: */*
>
* Request completely sent off
< HTTP/1.1 200 OK
< Date: Fri, 21 Feb 2025 16:07:27 GMT
< Content-Type: text/html; charset=UTF-8
< Connection: close
< Cache-Control: no-cache,no-store
< Expires: Thu, 01 Jan 1970 00:00:00 GMT
< Pragma: no-cache
< Set-Cookie: ...
< X-Content-Type-Options: nosniff
< RateLimit-Limit: HttpRequestRatePerPort:1500/m
< RateLimit-Remaining: HttpRequestRatePerPort:1499
< RateLimit-Reset: HttpRequestRatePerPort:47s
< X-Report-Abuse: https://msrc.microsoft.com/report/abuse
< x-ms-ratelimit-limit: 1500
< x-ms-ratelimit-remaining: 1496
< x-ms-ratelimit-used: 4
< x-ms-ratelimit-reset: 0
< Host: localhost:8888
< X-Powered-By: PHP/8.2.26
< X-Robots-Tag: noindex, nofollow
< Referrer-Policy: same-origin
< VsSaaS-Request-Id: 47d44f10-5456-4304-b353-51c2e46aebbb
< Strict-Transport-Security: max-age=31536000; includeSubDomains
< X-Served-By: tunnels-prod-rel-euw-v3-cluster
<
* Closing connection
Hello World!%

[szilvesztercsab]

Actually I cannot reproduce this via a devtunnel host invocation, so this must be a code-tunnel issue. I'll look at vscode issues to figure it out. Apologies if this was the wrong forum to bring this up. Feel free to close the issue if you have nothing else to contribute.