preevy icon indicating copy to clipboard operation
preevy copied to clipboard

[Bug]: Tunnel server | no active tunnel found

Open caslayoort opened this issue 1 year ago • 4 comments

What happened?

When trying to deploy a service with a custom domain, I run into the issue that the tunnel server does not seem to create or establish the tunnel connection.

The setup I run is a single machine with docker 24.0.5 and haproxy. The haproxy is configured to redirect http traffic to https and send all incomming traffic everything to port 3000. Within Docker, i run the tunnel server. The preevy (preevy/0.0.63 darwin-x64 node-v20.5.1) profile is configured to deploy on AWS Lightsail, the app itself runs perfectly fine. If I login to AWS and expose all ports to my IP and set an accepted domain in my /etc/hosts file, it runs fine.

From my local machine i can test the tunnel server and it works fine too, considering the documentation:

ssh -I ~/.ssh/<random_ssh_key> -R /my-tunnel:localhost:5000 my-sub.domain.com -p 2222 hello
lib_contains_symbol: /Users/<username>/.ssh/<random_ssh_key> does not contain expected string C_GetFunctionList
provider /Users/<username>/.ssh/<random_ssh_key> is not a PKCS11 library

{"clientId":"bbkfv7w0","tunnels":{"/my-tunnel":"http://my-tunnel-bbkfv7w0.my-sub.domain.com/"},"baseUrl":{"hostname":"my-sub.domain.com","port":"","protocol":"http:"},"rootUrl":"http://my-sub.domain.com/"}

However, i am getting the folowing error:

Preview environment <environment_name> provisioned at: <AWS_Lightsail_VM_IP>
✖ Getting tunnel URLs...
    Error: Failed to connect to docker proxy at http://preevy_proxy-<environment_name>-kvf384sz.my-sub.domain.com/: 502: Bad Gateway

The bad gateway is caused by not having a tunnel up and running (this message also appears when I try to go the URL itself). However, in the docker logs you do see the command incoming to bring the tunnel up but it doesnt seem to be responding to it.

Docker logs
{"level":20,"time":1713176509086,"pid":28,"hostname":"6038dff95c30","name":"ssh_server","connectionId":"ssh-client-a4f1n2p","msg":"accepting connection"}
{"level":20,"time":1713176509332,"pid":28,"hostname":"6038dff95c30","name":"ssh_server","clientId":"kvf384sz","envId":"","connectionId":"ssh-client-a4f1n2p","msg":"session"}
{"level":20,"time":1713176509333,"pid":28,"hostname":"6038dff95c30","name":"ssh_server","clientId":"kvf384sz","envId":"","connectionId":"ssh-client-a4f1n2p","msg":"session"}
{"level":20,"time":1713176509560,"pid":28,"hostname":"6038dff95c30","name":"ssh_server","clientId":"kvf384sz","envId":"","connectionId":"ssh-client-a4f1n2p","msg":"exec {\"command\":\"hello\"}"}
{"level":20,"time":1713176509561,"pid":28,"hostname":"6038dff95c30","name":"ssh_server","clientId":"kvf384sz","envId":"","connectionId":"ssh-client-a4f1n2p","msg":"exec {\"command\":\"tunnel-url - - - - - preevy_proxy-\"}"}
{"level":20,"time":1713176509732,"pid":28,"hostname":"6038dff95c30","name":"ssh_server","clientId":"kvf384sz","envId":"","connectionId":"ssh-client-a4f1n2p","msg":"client end"}
{"level":20,"time":1713176565697,"pid":28,"hostname":"6038dff95c30","name":"app","msg":"request {\"method\":\"GET\",\"url\":\"//tunnels\",\"headers\":{\"host\":\"preevy_proxy--kvf384sz.my-sub.domain.com\",\"accept\":\"*/*\",\"accept-language\":\"*\",\"sec-fetch-mode\":\"cors\",\"user-agent\":\"undici\",\"accept-encoding\":\"br, gzip, deflate\",\"x-forwarded-for\":\"\"}}"}
{"level":40,"time":1713176565698,"pid":28,"hostname":"6038dff95c30","msg":"no active tunnel for {\"url\":\"//tunnels\",\"method\":\"GET\",\"host\":\"preevy_proxy--kvf384sz.my-sub.domain.com\"}"}
{"level":40,"time":1713176566368,"pid":28,"hostname":"6038dff95c30","msg":"caught error: '_BadGatewayError: No active tunnel found\n    at validateProxyRequest (/app/src/proxy/index.ts:117:13)\n    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n    at  (/app/src/proxy/index.ts:135:47)\n    at  (/app/src/http-server-helpers.ts:115:5) {\n  statusCode: 502,\n  clientMessage: 'No active tunnel found',\n  cause: undefined,\n  responseHeaders: undefined\n}' in GET //tunnels"}
{"level":20,"time":1713176566849,"pid":28,"hostname":"6038dff95c30","name":"app","msg":"request {\"method\":\"GET\",\"url\":\"//tunnels\",\"headers\":{\"host\":\"preevy_proxy--kvf384sz.my-sub.domain.com\",\"accept\":\"*/*\",\"accept-language\":\"*\",\"sec-fetch-mode\":\"cors\",\"user-agent\":\"undici\",\"accept-encoding\":\"br, gzip, deflate\",\"x-forwarded-for\":\"\"}}"}
{"level":40,"time":1713176566850,"pid":28,"hostname":"6038dff95c30","msg":"no active tunnel for {\"url\":\"//tunnels\",\"method\":\"GET\",\"host\":\"preevy_proxy--kvf384sz.my-sub.domain.com\"}"}

When looking in Lightsail, it looks like the system does have SSH exposed to the internet without it being restricted to a specific IP.

Within Docker I use the following docker-compose file:

Docker compose
version: '3.7'

configs: saas-public-key: file: /etc/certs/preview-proxy/saas.key.pub

services: proxy: build: context: . restart: always image: preview-proxy environment: SSH_HOST_KEY_PATH: /opt/preevy/ssh-host-key BASE_URL: ${BASE_URL:-http://my-sub.domain.com} SAAS_BASE_URL: ${SAAS_BASE_URL:-http://my-sub.domain.com:3001} SAAS_JWT_ISSUER: ${SAAS_JWT_ISSUER:-my-sub.domain.com} DEBUG: '1'

volumes:
  - ./ssh:/app/ssh:ro,delegated
  - /opt/preevy:/opt/preevy:ro,delegated
  - /etc/letsencrypt/live/my-sub.domain.com/fullchain.pem:/app/tls/cert.pem:ro,delegated
  - /etc/letsencrypt/live/my-sub.domain.com/privkey.pem:/app/tls/key.pem:ro,delegated

ports:
  - '3000:3000'
  - '2222:2222'

healthcheck:
  test: wget --no-verbose --tries=1 --spider http://localhost:3000/healthz || exit 1
  interval: 10s
  retries: 4
  start_period: 20s
  timeout: 10s

configs:
  - source: saas-public-key
    target: /etc/certs/preview-proxy/saas.key.pub

Add screenshots

afbeelding

Steps to reproduce the behavior

preevy up --profile AWS -f preevy-compose.yml --id <environment_name> --tunnel-url "ssh://my-sub.domain.com:2222"

Expected behavior

The environment gets built and the proxy server will create and maintain a tunnel to the Lightsail VM.

What OS are you seeing the problem on?

Linux

Additional context

No response

Record

  • [X] I agree to follow this project's Code of Conduct

caslayoort avatar Apr 15 '24 12:04 caslayoort

Hey @caslayoort, thanks for the bug reporting. Can you share also the Docker logs for the preevy_proxy container running in your lightsail machine? It's responsible to open and manage the tunnels from the VM side. You can get it with Preevy, by using preevy logs preevy_proxy from your project directory.

Yshayy avatar Apr 17 '24 07:04 Yshayy

Hi @Yshayy,

it looks like there is just an handshake issue:

✔ Connected to remote docker socket
preevy_proxy-1  | [12:21:16.204] ERROR (1): Timed out while waiting for handshake
preevy_proxy-1  |     err: {
preevy_proxy-1  |       "type": "Error",
preevy_proxy-1  |       "message": "Timed out while waiting for handshake",
preevy_proxy-1  |       "stack":
preevy_proxy-1  |           Error: Timed out while waiting for handshake
preevy_proxy-1  |               at Timeout._onTimeout (file:///app/index.mjs:17897:27)
preevy_proxy-1  |               at listOnTimeout (node:internal/timers:569:17)
preevy_proxy-1  |               at process.processTimers (node:internal/timers:512:7)
preevy_proxy-1  |       "level": "client-timeout"
preevy_proxy-1  |     }

My apologies for the late reply, please let me know if there is any more data you would need

caslayoort avatar Apr 24 '24 12:04 caslayoort

Hi @Yshayy, would you happen to know a timeline for this issue?

caslayoort avatar May 02 '24 10:05 caslayoort

@caslayoort a few questions to help debugging

  1. You have port 2222 open on the host running tunnel server, and it's not going via haproxy, right?
  2. Can you run the same test (using the ssh CLI) from the environment? You can run preevy shell <env-id> to get a shell on the environment.
  3. Can you redeploy the env using preevy up --debug and post the output of preevy logs preevy_proxy?

royra avatar May 12 '24 00:05 royra

Hi @royra, I was under the assumption that the ssh tunnel was set up from the tunnel server and the port 2222 didn't need to be available other than for the solution deploying it. The tunnel server fires the command to bring the server up, which is why I enabled a firewall on AWS to only allow a certain IP to access the tunnel server SSH port as a security reason since it accepts all ssh keys you throw at it.

After looking at your questions, i disabled the firewall and it kinda works now (getting a 401 on the preevy_proxy but it does deploy and bring up the tunnel server so will look at what / why that goes wrong on a later point in time).

Just for my understanding, what security measures are in place on the ssh port to prevent abuse? The fact it has to be publicly available and accept any ssh key, I am not as comfortable with if there is nothing in place preventing it of becoming a security risk.

Another thing I did notice and am curious about, The moment you stop using the default tunnel server and using you own, the Lightsail instance exposes all ports to public internet. Why is a tunnel server solution needed if you could redirect traffic?

caslayoort avatar May 17 '24 13:05 caslayoort

Hey @caslayoort,

For the tunnel server, the SSH port needs to be accessible from the environment machine and from the machine running preevy up (e.g, the CI runner). HTTP needs to be accessible from wherever you want to access your services.

Note that the attack surface into the tunnel server via SSH is smaller than usual. The tunnel server implements a custom SSH based on the Node.js ssh2 package. No shell support is implemented.

To further reduce the attack surface, you can hide the SSH protocol behind TLS by exposing only port 8443. This way regular SSH clients will not be able to access SSH directly. You will need to provide the TLS certificate to the tunnel server - see instructions. This is how the publicly available tunnel server is configured.

For the environment machine (lightsail instance in your case), only the standard SSH port needs to be accessible from the machine running preevy up. No other ports need to be open. The preevy agent running in the environment initiates an outgoing SSH (or SSH over TLS) connection to the tunnel server. The tunnel server proxies incoming requests via the SSH tunnel created using this connection. See this blog post for more details.

Hope this clears things up. Good luck making your setup work, would love to hear your feedback and LMK if you have any questions.

royra avatar May 17 '24 16:05 royra

@caslayoort any updates?

royra avatar May 28 '24 15:05 royra

Hi @royra,

Thanks for the clarification, I am going to look into hiding it further by hiding it behind TLS.

It is working now. Everything is deploying fine, however I still get an error 401 at the last step (getting tunnel urls). If you guess the tunnel URL you can still access it perfectly fine.

caslayoort avatar May 30 '24 13:05 caslayoort

Hi @royra , any idea what could cause the Unauthorized error mentioned by @caslayoort ?

✖ Getting tunnel URLs...
    Error: Failed to connect to docker proxy at
    http://preevy_proxy-site-feature-preevy-test-5uix5has.<our-custom-tunnel>/: 401: Unauthorized

Something misconfigured on the tunnel server perhaps?

ChrisTitos avatar Jun 07 '24 09:06 ChrisTitos

Hi @royra , any idea what could cause the Unauthorized error mentioned by @caslayoort ?

✖ Getting tunnel URLs...
    Error: Failed to connect to docker proxy at
    http://preevy_proxy-site-feature-preevy-test-5uix5has.<our-custom-tunnel>/: 401: Unauthorized

Something misconfigured on the tunnel server perhaps?

It would be helpful to post the logs from the tunnel server, preferably with DEBUG=1.

royra avatar Jun 10 '24 17:06 royra

Hi @royra,

The URLs command:

✔ Loading compose file: preevy-compose.yml
    Error: Failed to connect to docker proxy at http://preevy_proxy-<id>-ia4cvlvw.sub.domain.com/: 401: Unauthorized

I gathered some info with wireshark as well since we had a look yesterday as well: It first calls //tunnels where it has a bearer JWT token:

{
  "iat": 1718114630,
  "iss": "preevy://urn:ietf:params:oauth:jwk-thumbprint:sha-256:<<redacted>>",
  "exp": 1723298630
}

But when it calls /login?env=preevy_proxy--ia4cvlvw&returnPath=%2F it does not contain the bearer token from what I can see with wireshark.

When we did look at the logs, it did confirm it did not recognise the JWT token, but it says it at the //tunnels step where we saw there actually was a token.

tunnel server logs - debug=1
{"level":20,"time":1718116081330,"pid":28,"hostname":"4621567c76ea","name":"app","msg":"request {\"method\":\"GET\",\"url\":\"//tunnels\",\"headers\":{\"host\":\"preevy_proxy-<<id>>-ia4cvlvw.sub.domain.com\",\"accept\":\"*/*\",\"accept-language\":\"*\",\"sec-fetch-mode\":\"cors\",\"user-agent\":\"node\",\"accept-encoding\":\"br, gzip, deflate\",\"x-forwarded-for\":\"<ip>\"}}"}

{"level":20,"time":1718116081330,"pid":28,"hostname":"4621567c76ea","msg":"not authenticated: 'no jwt in request'"}

{"level":40,"time":1718116081673,"pid":28,"hostname":"4621567c76ea","msg":"caught error: 'RedirectError: Redirected\n    at redirectToLoginError (/app/src/proxy/index.ts:65:42)\n    at validatePrivateTunnelRequest (/app/src/proxy/index.ts:87:13)\n    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)\n    at validateProxyRequest (/app/src/proxy/index.ts:126:14)\n    at <anonymous> (/app/src/proxy/index.ts:135:47)\n    at <anonymous> (/app/src/http-server-helpers.ts:115:5) {\n  statusCode: 307,\n  clientMessage: 'Redirected',\n  cause: undefined,\n  responseHeaders: {\n    location: 'http://auth.sub.domain.com/login?env=<<id>>&returnPath=%2F'\n  },\n  location: 'http://auth.sub.domain.com/login?env=preevy_proxy-<<id>>-ia4cvlvw&returnPath=%2F'\n}' in GET //tunnels"}

{"level":20,"time":1718116081674,"pid":28,"hostname":"4621567c76ea","name":"app","msg":"request {\"method\":\"GET\",\"url\":\"/login?env=preevy_proxy-<<id>>-ia4cvlvw&returnPath=%2F\",\"headers\":{\"host\":\"auth.sub.domain.com\",\"accept\":\"*/*\",\"accept-language\":\"*\",\"sec-fetch-mode\":\"cors\",\"user-agent\":\"node\",\"accept-encoding\":\"br, gzip, deflate\",\"x-forwarded-for\":\"<ip>\"}}"}

{"level":30,"time":1718116081674,"pid":28,"hostname":"4621567c76ea","name":"app","reqId":"req-5j","req":{"method":"GET","url":"/login?env=preevy_proxy-<<id>>-ia4cvlvw&returnPath=%2F","hostname":"auth.sub.domain.com","remoteAddress":"<docker host ip","remotePort":49228},"msg":"incoming request"}

{"level":30,"time":1718116081676,"pid":28,"hostname":"4621567c76ea","name":"app","reqId":"req-5j","res":{"statusCode":401},"err":{"type":"_UnauthorizedError","message":"Unauthorized","stack":"Error: Unauthorized\n    at Object.<anonymous> (/app/src/app/login.ts:50:15)\n    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)","statusCode":401,"clientMessage":"Unauthorized"},"msg":"Unauthorized"}

{"level":30,"time":1718116081816,"pid":28,"hostname":"4621567c76ea","name":"app","reqId":"req-5j","res":{"statusCode":401},"responseTime":141.20722800004296,"msg":"request completed"}

{"level":20,"time":1718116082901,"pid":28,"hostname":"4621567c76ea","name":"app","msg":"request {\"method\":\"GET\",\"url\":\"//tunnels\",\"headers\":{\"host\":\"preevy_proxy-<<id>>-ia4cvlvw.sub.domain.com\",\"accept\":\"*/*\",\"accept-language\":\"*\",\"sec-fetch-mode\":\"cors\",\"user-agent\":\"node\",\"accept-encoding\":\"br, gzip, deflate\",\"x-forwarded-for\":\"<ip>\"}}"}

{"level":20,"time":1718116082902,"pid":28,"hostname":"4621567c76ea","msg":"not authenticated: 'no jwt in request'"}

caslayoort avatar Jun 11 '24 14:06 caslayoort

Any ideas @royra ?

ChrisTitos avatar Jun 18 '24 16:06 ChrisTitos

@ChrisTitos sorry for the late reply.

The /tunnels request should have a JWT in a header: Authorization: Bearer <JWT>. The logs (and the 401 response) indicate that for some reason the token is not there, or invalid, which is weird.

Are you using the latest release in the CLI v0.0.64?

I've added logs with the headers and published a canary version, install it with npm i -g [email protected], run with --debug and see the logs.

royra avatar Jun 18 '24 18:06 royra

Hi @royra,

I just upgraded the cli version to the 0.0.65 version you mentioned. In the output i am getting the following error:

Deploy step done in 86.77s
Preview environment test provisioned at: ip
⠋ Getting tunnel URLs...socketServer closed
Fetching from compose tunnel agent at http://preevy_proxy-test-ia4cvlvw.sub.domain.com//tunnels, headers: {
  Authorization: 'Bearer <redacted>'
}
⠸ Getting tunnel URLs...Inbound: CHANNEL_EOF (r:27)
Inbound: CHANNEL_CLOSE (r:27)
Outbound: Sending CHANNEL_CLOSE (r:4)
⠼ Getting tunnel URLs...Inbound: CHANNEL_EOF (r:36)
Inbound: CHANNEL_CLOSE (r:36)
Outbound: Sending CHANNEL_CLOSE (r:1)
⠦ Getting tunnel URLs...Failed to query tunnels: AgentFetchError: Failed to connect to preevy agent at http://preevy_proxy-test-ia4cvlvw.sub.domain.com/: 502: Bad Gateway
    at <anonymous> (/usr/local/lib/node_modules/preevy/node_modules/@preevy/core/src/compose-tunnel-agent-client.ts:186:11)
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async RetryOperation._fn (/usr/local/lib/node_modules/preevy/node_modules/p-retry/index.js:50:12) {
  attemptNumber: 1,
  retriesLeft: 10
}
⠏ Getting tunnel URLs...Fetching from compose tunnel agent at http://preevy_proxy-test-ia4cvlvw.sub.domain.com//tunnels, headers: {
  Authorization: 'Bearer <redacted>'
}
⠧ Getting tunnel URLs...Failed to query tunnels: AgentFetchError: Failed to connect to preevy agent at http://preevy_proxy-test-ia4cvlvw.sub.domain.com/: 401: Unauthorized
    at <anonymous> (/usr/local/lib/node_modules/preevy/node_modules/@preevy/core/src/compose-tunnel-agent-client.ts:186:11)
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async RetryOperation._fn (/usr/local/lib/node_modules/preevy/node_modules/p-retry/index.js:50:12) {
  attemptNumber: 2,
  retriesLeft: 9
}

caslayoort avatar Jun 20 '24 08:06 caslayoort

It looks like the Authorization header is sent by the client but doesn't get to the tunnel server. How is the tunnel server exposed? Maybe there is some box in the middle like a gateway/proxy/ALB? You can try running it locally and see whether the problem reproduces.

royra avatar Jun 20 '24 08:06 royra

Hi @royra,

Hi, I disabled the proxy and it worked, so i had another look at the config. It looks like the tunnel server does not accept the request in HTTPS for the /tunnels endpoint specifically. The HAproxy was configured to redirect all http to https and serve the ssl certificate. Worked great for the application in general, just the /tunnels request did not like it. Excluded it and looks like it works fine now.

HAproxy config
frontend http
    mode http
    option forwardfor
    bind    :80

    acl do_not_redirect path_beg /tunnels

    redirect scheme https code 301 if !{ ssl_fc } !do_not_redirect
    default_backend preevy

frontend https
    mode http
    option forwardfor
    bind    :443 ssl crt /etc/haproxy/ssl/ alpn h2,http/1.1
    default_backend preevy

backend preevy
    mode http
    option forwardfor
    server  preevy 127.0.0.1:3000 check

Thank you both for helping to troubleshoot in this thread

caslayoort avatar Jun 20 '24 09:06 caslayoort