search

aws-samples / aws-iot-securetunneling-localproxy

AWS Iot Secure Tunneling local proxy reference C++ implementation
https://docs.aws.amazon.com/iot/latest/developerguide/what-is-secure-tunneling.html
Apache License 2.0
74 stars 71 forks source link

(docker): kex_exchange_identification: read: Connection closed by remote host #45

Closed plafer closed 3 years ago

plafer commented 3 years ago

Describe the bug After setting up the docker using docker-build.sh, running it while exposing port 5555, and trying to connect using ssh jetson@localhost -p 5555, I get the error message kex_exchange_identification: read: Connection reset by peer.

To Reproduce

Steps to reproduce the behavior:

  1. Set up AWS greengrass Secure Tunneling component on device.
  2. Open tunnel to thing in AWS console.
  3. On your laptop (Ubuntu 20.04, x86), run docker-build.sh.
  4. On laptop, run docker run --expose 5555 -p 5555:5555 --name localproxy --rm -it aws-iot-securetunneling-localproxy:latest bash
  5. In docker container, run AWSIOT_TUNNEL_ACCESS_TOKEN=<token> ./localproxy -r us-east-1 -s 5555
  6. In AWS console, tunnel is Open, Source connection state: Connected and Destination connection state: Connected
  7. On laptop, run ssh jetson@localhost -p 5555. Output: kex_exchange_identification: read: Connection reset by peer

EDIT: Output also is "kex_exchange_identification: Connection closed by remote host". Not sure what causes one or the other.

Expected behavior

I'd expect the tunnel to work and to be ssh'd into my device.

Actual behavior

The connection is reset by peer.

EDIT: The latest I got was "kex_exchange_identification: Connection closed by remote host".

localproxy Logs root@6f12375810ac:/home/aws-iot-securetunneling-localproxy# ./localproxy -r us-east-1 -s 5555 -v 6 [2021-05-20T18:21:01.554320]{14}[debug] v2 local proxy starts with v1 local proxy format [2021-05-20T18:21:01.554352]{14}[debug] /home/aws-iot-securetunneling-localproxy/config does not exist! [2021-05-20T18:21:01.554379]{14}[info] Starting proxy in source mode [2021-05-20T18:21:01.555499]{14}[trace] Setting up web socket... [2021-05-20T18:21:01.555579]{14}[info] Attempting to establish web socket connection with endpoint wss://data.tunneling.iot.us-east-1.amazonaws.com:443 [2021-05-20T18:21:01.555590]{14}[trace] Resolving proxy host: data.tunneling.iot.us-east-1.amazonaws.com [2021-05-20T18:21:01.595973]{14}[debug] Resolved proxy server IP: 34.207.45.197 [2021-05-20T18:21:01.629339]{14}[debug] Connected successfully with proxy server [2021-05-20T18:21:01.629460]{14}[trace] Performing SSL handshake with proxy server [2021-05-20T18:21:01.726366]{14}[debug] Successfully completed SSL handshake with proxy server [2021-05-20T18:21:01.726463]{14}[trace] Performing websocket handshake with proxy server [2021-05-20T18:21:01.726941]{14}[trace] Web socket ugprade request(*not entirely final): GET /tunnel?local-proxy-mode=source HTTP/1.1 Host: data.tunneling.iot.us-east-1.amazonaws.com Upgrade: websocket Connection: upgrade Sec-WebSocket-Key: uf2YV+uawo7keVQLTQ2YjQ== Sec-WebSocket-Version: 13 Sec-WebSocket-Protocol: aws.iot.securetunneling-2.0 access-token: ACCESS_TOKEN_REMOVED User-Agent: localproxy linux 64-bit/boost-1.69.0/openssl-1.1.1/protobuf-3.6.1

[2021-05-20T18:21:01.863909]{14}[trace] Web socket upgrade response: HTTP/1.1 101 Switching Protocols Date: Thu, 20 May 2021 18:21:01 GMT Content-Length: 0 Connection: upgrade channel-id: 1245f1fffef3f0cf-00005699-0003233b-ded6307b2f44b9fc-bb003686 upgrade: websocket sec-websocket-accept: 5zQZlepibG0Glh1ObHOeXWzima8= sec-websocket-protocol: aws.iot.securetunneling-2.0

[2021-05-20T18:21:01.864050]{14}[info] Web socket session ID: 1245f1fffef3f0cf-00005699-0003233b-ded6307b2f44b9fc-bb003686 [2021-05-20T18:21:01.864088]{14}[debug] Web socket subprotocol selected: aws.iot.securetunneling-2.0 [2021-05-20T18:21:01.864125]{14}[info] Successfully established websocket connection with proxy server: wss://data.tunneling.iot.us-east-1.amazonaws.com:443 [2021-05-20T18:21:01.864178]{14}[debug] Seting up web socket pings for every 5000 milliseconds [2021-05-20T18:21:01.864360]{14}[trace] Waiting for service ids... [2021-05-20T18:21:01.864431]{14}[trace] async_web_socket_read_loop_for_service_ids [2021-05-20T18:21:01.864461]{14}[debug] Scheduled next read: [2021-05-20T18:21:01.864584]{14}[debug] No serviceId_to_tcp_server mapping for service_id: [2021-05-20T18:21:01.864637]{14}[debug] Extracting service Ids from control message 5 [2021-05-20T18:21:01.864707]{14}[trace] Service id received: [2021-05-20T18:21:01.864758]{14}[trace] SSH [2021-05-20T18:21:01.864796]{14}[trace] Validating service ids configuration [2021-05-20T18:21:01.864828]{14}[info] Updated port mapping for v1 format: [2021-05-20T18:21:01.864858]{14}[info] SSH = 5555 [2021-05-20T18:21:01.864892]{14}[trace] Setting up tcp sockets [2021-05-20T18:21:01.864925]{14}[trace] Clearing all ws data buffers [2021-05-20T18:21:01.864972]{14}[trace] Finished Clearing all ws data buffers [2021-05-20T18:21:01.865019]{14}[trace] Initializing tcp servers ... [2021-05-20T18:21:01.865072]{14}[trace] Setting up source tcp sockets [2021-05-20T18:21:01.865104]{14}[trace] Setting up tcp socket for service id: SSH [2021-05-20T18:21:01.865148]{14}[debug] Resolving bind address host: localhost [2021-05-20T18:21:01.865208]{14}[debug] Port to connect 5555 [2021-05-20T18:21:01.865274]{14}[debug] Starting web socket read loop continue reading... [2021-05-20T18:21:01.865646]{14}[debug] Resolved bind IP: 127.0.0.1 [2021-05-20T18:21:01.865760]{14}[info] Listening for new connection on port 5555

ssh logs ssh -vvvvA jetson@localhost -p 5555 OpenSSH_8.2p1 Ubuntu-4ubuntu0.2, OpenSSL 1.1.1f 31 Mar 2020 debug1: Reading configuration data /home/plafer/.ssh/config debug1: Reading configuration data /etc/ssh/ssh_config debug1: /etc/ssh/ssh_config line 19: include /etc/ssh/ssh_config.d/.conf matched no files debug1: /etc/ssh/ssh_config line 21: Applying options for debug2: resolving "localhost" port 5555 debug2: ssh_connect_direct debug1: Connecting to localhost [127.0.0.1] port 5555. debug1: Connection established. debug1: identity file /home/plafer/.ssh/id_rsa type 0 debug1: identity file /home/plafer/.ssh/id_rsa-cert type -1 debug1: identity file /home/plafer/.ssh/id_dsa type -1 debug1: identity file /home/plafer/.ssh/id_dsa-cert type -1 debug1: identity file /home/plafer/.ssh/id_ecdsa type -1 debug1: identity file /home/plafer/.ssh/id_ecdsa-cert type -1 debug1: identity file /home/plafer/.ssh/id_ecdsa_sk type -1 debug1: identity file /home/plafer/.ssh/id_ecdsa_sk-cert type -1 debug1: identity file /home/plafer/.ssh/id_ed25519 type -1 debug1: identity file /home/plafer/.ssh/id_ed25519-cert type -1 debug1: identity file /home/plafer/.ssh/id_ed25519_sk type -1 debug1: identity file /home/plafer/.ssh/id_ed25519_sk-cert type -1 debug1: identity file /home/plafer/.ssh/id_xmss type -1 debug1: identity file /home/plafer/.ssh/id_xmss-cert type -1 debug1: Local version string SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.2 kex_exchange_identification: Connection closed by remote host

Environment (please complete the following information):

Additional context

Device is a Jetson Nano running Ubuntu 18.04. Secure Tunneling config is:

componentType: "GENERIC" configuration: accessControl: aws.greengrass.ipc.mqttproxy: aws.greengrass.SecureTunneling:mqttproxy:1: operations:

plafer commented 3 years ago

I can successfully SSH into my jetson nano without the tunnel.

kareali commented 3 years ago

The error kex_exchange_identification: read: Connection closed by remote host is an SSH error, which means that the tunnel is working as expected establishing TCP connection and forwarding traffic to the device but seems that the SSH daemon on the device drops the connection for no good reason(possible SSH configuration issue), Could you try SSHing from your laptop to the device directly without utilizing a tunnel?

kareali commented 3 years ago

I will try reproducing the problem on my ubuntu machine.

plafer commented 3 years ago

Here are the greengrass SecureTunneling logs in case that helps.

$ sudo greengrass-cli logs get -lf /greengrass/v2/logs/aws.greengrass.SecureTunneling.log 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [INFO ] 2021-05-20 12:49:28.559 [Thread-0] SubscribeResponseHandler - Received new tunnel notification message.. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.570 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: 2021-05-20T12:49:28.568Z [INFO] {Config.cpp}: Successfully fetched JSON config file: {. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.569 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: 2021-05-20T12:49:28.567Z [WARN] {FileUtils.cpp}: Permissions to given file/dir path '/tmp/' is not set to recommended value... {Permissions: {desired: 745, actual: 777}}. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.571 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "endpoint": "replace_with_endpoint_value",. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.571 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "key": "replace_with_private_key_file_location",. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.571 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "cert": "replace_with_certificate_file_location",. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.572 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "root-ca": "replace_with_root_ca_file_location",. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.573 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "level": "ERROR",. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.573 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "logging": {. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.572 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "thing-name": "replace_with_thing_name",. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.574 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: },. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.574 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "file": "/var/log/aws-iot-device-client/aws-iot-device-client.log". {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.573 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "type": "STDOUT",. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.575 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "enabled": false,. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.574 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "jobs": {. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.575 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "handler-directory": "replace_with_path_to_handler_dir". {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.577 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: },. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.577 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "enabled": true. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.576 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "tunneling": {. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.575 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: },. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.578 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "enabled": false,. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.577 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "device-defender": {. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.578 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "interval": 300. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.578 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: },. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.579 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "fleet-provisioning": {. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.579 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "enabled": false,. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.579 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "template-name": "replace_with_template_name",. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.581 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: 2021-05-20T12:49:28.568Z [DEBUG] {Config.cpp}: Did not find a runtime configuration file, assuming Fleet Provisioning has not run for this device. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.580 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: "csr-file": "replace_with_csr-file-path". {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.580 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: }. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING} 2021-05-20 12:49:28 EDT [INFO] greengrass.SecureTunneling: stdout. [ERROR] 2021-05-20 12:49:28.580 [pool-3-thread-2] SubscribeResponseHandler - Secure Tunneling Process: }. {scriptName=services.aws.greengrass.SecureTunneling.lifecycle.run.script, serviceName=aws.greengrass.SecureTunneling, currentState=RUNNING}

kareali commented 3 years ago

@plafer Thanks! Just to rule out docker networking issues, could you try the following,

  1. From terminal A, run the docker container as per the steps you added, then run the tunnel in the source mode (step 4 and step 5 in the To Reproduce section).
  2. From terminal B, get into the container and try to SSH from inside (as opposed to SSHing via the port exposed by Docker). 
    # Get in the container
docker exec -it localproxy bash
# Install SSH daemon on the container
apt-get update
apt install openssh-server
service ssh start
# Try SSHing through the tunnel from the container.
ssh jetson@localhost -p 5555
plafer commented 3 years ago

Well, that works! :) I'm not sure how to fix the docker part then...

kareali commented 3 years ago

@plafer I think I figured out the issue, the localproxy binds to 127.0.0.1, which is not accessible from outside the container, it needs to bind to the special ip 0.0.0.0, so we need to fix that.

YSUN-coder commented 3 years ago

ssh jetson@localhost -p 5555

Also, could we have a solution to use the SSH outside the container?

kareali commented 3 years ago

@plafer @YSUN-coder I have update the instructions and the docker-run script, to make the localproxy accessible from outside the container, you use

./docker-run.sh -p 5555
# And then from inside the container, make sure to use 0.0.0.0 for binding by using the -b option
./localproxy -s 5555 -b 0.0.0.0 -r <REGION> -t <TOKEN>