Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

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

Open
szilvesztercsab opened this issue Feb 21, 2025 · 4 comments
Open

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

szilvesztercsab opened this issue Feb 21, 2025 · 4 comments

Comments

@szilvesztercsab
Copy link

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:

Image

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 szilvesztercsab changed the title Connection to tunnel doesn't end after response sent Request to forwarded port doesn't finish after response was sent Feb 21, 2025
@szilvesztercsab
Copy link
Author

szilvesztercsab commented Feb 21, 2025 •
edited
Loading

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
Copy link
Author

szilvesztercsab commented Feb 21, 2025 •
edited
Loading

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
Copy link
Author

szilvesztercsab commented Feb 21, 2025 •
edited
Loading

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 szilvesztercsab changed the title Request to forwarded port doesn't finish after response was sent Request to forwarded port doesn't finish after response was recieved Feb 21, 2025
@szilvesztercsab
Copy link
Author

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.

@szilvesztercsab szilvesztercsab mentioned this issue Feb 21, 2025
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@szilvesztercsab