Teleport: Seeing `closed network connection` on proxy nodes in IoT mode

[JonGilmore]

What happened:
While running IoT mode, we're seeing thousands of errors that _appear_ to be related to connection timeouts as follows:

use of closed network connection *net.OpError. reversetunnel/transport.go:305

We're running NLB's in front of our auth and proxy clusters. We have ~4500 nodes connected at the moment, but this is expected to continue to scale to ~10,000.

Proxy cluster config:

teleport:
  cache:
    # use in memory cache to speed up connections of many teleport nodes back to proxy
    type: in-memory
  auth_token: /etc/teleport/proxy_token
  log:
    output: syslog
    severity: INFO
  data_dir: /var/lib/teleport
  auth_servers:
    - teleport-auth.domain.internal:3025
  connection_limits:
    max_connections: 65000
    max_users: 1000
  keep_alive_interval: 1m
  keep_alive_count_max: 3
auth_service:
  enabled: no
ssh_service:
  enabled: no
proxy_service:
  enabled: yes
  listen_addr: 0.0.0.0:3023
  tunnel_listen_addr: 0.0.0.0:3024
  web_listen_addr: 0.0.0.0:3080
  ssh_public_addr: shell.domain.com:3023
  public_addr: shell.domain.com:3080

Auth cluster config:

teleport:
  log:
    output: syslog
    severity: INFO
  storage:
    type: dynamodb
    region: us-east-2
    table_name: teleportauth
    audit_events_uri: 'dynamodb://teleportauth-events'
    audit_sessions_uri: file:///var/lib/teleport/audit/sessions
  connection_limits:
    max_connections: 65000
    max_users: 1000
auth_service:
  keep_alive_interval: 1m
  keep_alive_count_max: 4
  enabled: yes
  tokens:
    - "proxy,node:/etc/teleport/proxy_token"
  session_recording: off
  license_file: /var/lib/teleport/license.pem
  listen_addr: 0.0.0.0:3025
  public_addr: teleport-auth.domain.internal:3025
  cluster_name: domain-4d05b3b4
  authentication:
    second_factor: off
    type: saml
proxy_service:
  enabled: no
ssh_service:
   enabled: yes

How to reproduce it (as minimally and precisely as possible):
No effort to reproduce this - it starts happening immediately.

Environment:

• Teleport version (use teleport version): 4.2.3 beta1
• Tsh version (use tsh version): 4.2.2
• OS (e.g. from /etc/os-release): 18.04.4

Browser environment

• Browser Version (for UI-related issues):
• Install tools:
• Others:

Relevant Debug Logs If Applicable

Feb 28 17:21:28 ip-10-66-16-215 /usr/local/bin/teleport[19400]: INFO [PROXY:SER] Cluster agent disconnected. trace.fields:map[cluster:domain-4d05b3b4] reversetunnel/localsite.go:348
Feb 28 17:21:28 ip-10-66-16-215 /usr/local/bin/teleport[19400]: ERRO [DISCOVERY] Disconnecting connection to domain-4d05b3b4 18.215.121.182:14581: agent disconnected. reversetunnel/conn.go:169
Feb 28 17:21:28 ip-10-66-16-215 /usr/local/bin/teleport[19400]: INFO [PROXY:SER] Cluster connection closed. trace.fields:map[cluster:domain-4d05b3b4] reversetunnel/localsite.go:325
Feb 28 17:21:31 ip-10-66-16-215 /usr/local/bin/teleport[19400]: WARN [PROXY:1]   Proxy transport failed: read tcp 10.66.16.215:54472->10.66.82.214:3025: use of closed network connection *net.OpError. reversetunnel/transport.go:305
Feb 28 17:21:31 ip-10-66-16-215 /usr/local/bin/teleport[19400]: WARN [PROXY:1]   Proxy transport failed: read tcp 10.66.16.215:54474->10.66.82.214:3025: use of closed network connection *net.OpError. reversetunnel/transport.go:305

┆Issue is synchronized with this Asana task by Unito

[JonGilmore]

@aelkugia or @benarent any updates on this? We're happy to perform more testing if you'd like help in getting to the bottom of this.

[aduston-rapid]

I've received reports recently from users complaining that sessions disconnect with an error after about 15 minutes. The way to reproduce is to just use teleport to open a session on a remote host. The connection will closer after about 10-15 minutes (I haven't timed it precisely) with the following error:

the connection was closed on the remote side on 18 Mar 20 07:19 MDT

I have also reproduced this in the browser using Google Chrome 80.0.3987.132 on Linux.

The teleport cluster is configured in AWS with a similar setup to what is described in the Running Teleport on AWS document and the terraform example code.

Teleport uses an ALB with an ACM certificate for the proxy web interface, and an NLB for the proxy ports 3023 and 3025. all hosts use reverse tunnels/IoT mode for connections. The proxy nodes connect to the auth nodes, which are in the VPC's private subnets via an internal NLB.

The AMI used to deploy the cluster is gravitational-teleport-marketplace-ami-oss-4.1.0-92c3dc07-bdfa-4e88-8c8b-e6187dac50af-ami-0649424667fb38a87.4, and the teleport version on the server is Teleport v4.1.0 git:v4.1.0-0-g3078799c go1.12.1.

Proxy configuration:

teleport:
  auth_token: /var/lib/teleport/token
  ca_pin: <my-ca-pin>
  nodename: <hostname>
  advertise_ip: <host-ip>
  log:
    output: syslog
    severity: INFO

  data_dir: /var/lib/teleport
  storage:
    type: dir
    path: /var/lib/teleport/backend
  auth_servers:
    - my-nlb-name.elb.us-west-2.amazonaws.com:3025

auth_service:
  enabled: no

ssh_service:
  enabled: no

proxy_service:
  enabled: yes
  listen_addr: 0.0.0.0:3023
  tunnel_listen_addr: 0.0.0.0:3024
  web_listen_addr: 0.0.0.0:3080
  public_addr: proxy.mydomain.com:443
  ssh_public_addr: proxy.mydomain.com:3023

Auth node configuration:

teleport:
  nodename: <hostname>
  advertise_ip: <host-ip>
  log:
    output: syslog
    severity: INFO

  data_dir: /var/lib/teleport
  storage:
    type: dynamodb
    region: us-west-2
    table_name: my-table
    audit_table_name: my-table-events
    audit_sessions_uri: s3://my-bucket/records

ssh_service:
  enabled: no

proxy_service:
  enabled: no

auth_service:
  enabled: yes
  listen_addr: 0.0.0.0:3025
  authentication:
    type: github
  tokens:
    - "node:static_token"

The user who initially raised this issue with me is using the following environment:

• tsh: v4.2.6 git:v4.2.6-0-gce1cbbf8 go1.13.2
• Operating System: Linux on WSL
• Operating System Version: Ubuntu 18.04.4 LTS (WSL version 10.0.18363.720)

The node the user is connecting to is running in the following environment:

• Teleport: v4.2.1 git:v4.2.1-0-gb16ee7d7 go1.13.2
• Operating System: CentOS Linux release 7.7.1908

The node's configuration is:

auth_service:
    enabled: false
proxy_service:
    enabled: false
ssh_service:
    enabled: true
    labels:
        distro: CentOS
        environment: <environment>
        instance_id: <instance_id>
        instance_type: t3.xlarge
        os_version: '7.7'
        region: us-west-2
    listen_addr: 0.0.0.0:3022
    client_idle_timeout: never
storage:
    path: /var/lib/teleport/backend
    type: dir
teleport:
    auth_servers:
    - proxy.mydomain.com:443
    auth_token: <static_token>
    ca_pin: <my_ca_pin>
    data_dir: /var/lib/teleport
    log:
        output: syslog
        severity: WARN
    nodename: <host_name>

These are the log messages I'm seeing on the proxy host:

Mar 18 17:30:55 <hostname>/usr/bin/teleport[19998]: WARN             http: named cookie not present request:GET /web web/apiserver.go:2057
Mar 18 17:30:57 <hostname>/usr/bin/teleport[19998]: WARN [PROXY:1]   Proxy transport failed: read tcp <this-proxy-ip>:40388-><auth-nlb-ip>:3025: use of closed network connection *net.OpError. reversetunnel/tr
Mar 18 17:30:57 <hostname>/usr/bin/teleport[19998]: WARN [PROXY:1]   Proxy transport failed: read tcp <this-proxy-ip>:40390-><auth-nlb-ip>:3025: use of closed network connection *net.OpError. reversetunnel/tr
Mar 18 17:30:57 <hostname>/usr/bin/teleport[19998]: WARN [PROXY:1]   Proxy transport failed: read tcp <this-proxy-ip>:40396-><auth-nlb-ip>:3025: use of closed network connection *net.OpError. reversetunnel/tr
Mar 18 17:30:58 <hostname>/usr/bin/teleport[19998]: WARN             http: named cookie not present request:GET /web web/apiserver.go:2057
Mar 18 17:31:04 <hostname>/usr/bin/teleport[19998]: ERRO             read tcp <this-proxy-ip>:3023-><proxy-nlb-ip>:60940: read: connection reset by peer
Mar 18 17:31:25 <hostname>/usr/bin/teleport[19998]: WARN             http: named cookie not present request:GET /web web/apiserver.go:2057
Mar 18 17:31:28 <hostname>/usr/bin/teleport[19998]: WARN             http: named cookie not present request:GET /web web/apiserver.go:2057
Mar 18 17:31:38 <hostname>/usr/bin/teleport[19998]: ERRO             read tcp <this-proxy-ip>:3024-><proxy-nlb-ip>:53752: read: connection reset by peer

I can provide other detail if it is useful. Would love to know what the status of this issue is. We're currently in the process of trialing Teleport in our organization, but this could be a deal-breaking bug for widespread adoption of the platform with our users.

[webvictim]

@aduston-rapid Please try adding this to your teleport.yaml and restarting any auth server instances you have:

auth_service:
  keep_alive_interval: 1m
  keep_alive_count_max: 3

I'm not saying you aren't experiencing the same issue, but we see many issues due to the default connection timeout on NLBs (which is 350 seconds, and cannot be changed). It's important to make sure that this isn't a different issue.

[JonGilmore]

I'm not saying you aren't experiencing the same issue, but we see many issues due to the default connection timeout on NLBs (which is 350 seconds, and cannot be changed). It's important to make sure that this isn't a different issue.

@webvictim - from looking at your code, you have a default keepalive set on the app of <350 seconds, right?

[webvictim]

The documentation says that the timeout is set to 15 minutes to mirror SSH, but it's possible that is now out of date.

[webvictim]

@JonGilmore You're correct that the actual default is set to 5 minutes now though, so the documentation should be updated to reflect that.

[JonGilmore]

based on what I'm seeing here, its wrong: https://github.com/gravitational/teleport/blob/v4.2.6/lib/defaults/defaults.go#L309

[JonGilmore]

@aduston-rapid Just curious, how many teleport nodes do you have currently? Seems like we have very similar configurations

[aduston-rapid]

@JonGilmore Currently this cluster is still new and in a sort of user acceptance testing / trial state, so it only has six nodes connected to it. The nodes aren't seeing heavy usage either. Maybe one or two users connecting to a couple of hosts a day.

[aduston-rapid]

@webvictim - I added the configuration you suggested and so far initially it appears that it does help. I've had a session open for about 20 minutes now without any disconnects.

Unfortunately it doesn't appear that the tooling that generates the configuration file for the AWS marketplace AMIs provides a way to easily add these parameters:

https://github.com/gravitational/teleport/blob/master/assets/marketplace/files/bin/teleport-generate-config#L68

Are these AMIs still actively maintained, and if so should I raise another request somewhere to have these parameters added to the AMI configuration?

[webvictim]

@aduston-rapid The default keep_alive_interval has been set to 5 minutes since around Teleport 4.1.0 so I'd expect this behaviour to have been mitigated a while ago.

Those AMI scripts are still maintained and used, for sure. I'll look at raising a PR to just add a keep_alive_interval of 1m to the Teleport config for auth servers by default in AMI builds.

[JonGilmore]

@JonGilmore Currently this cluster is still new and in a sort of user acceptance testing / trial state, so it only has six nodes connected to it. The nodes aren't seeing heavy usage either. Maybe one or two users connecting to a couple of hosts a day.

right on. I think you're facing a different issue just based on this:
read: connection reset by peer
We're not seeing any connection resets in our logs.