From ebe7e98cdcc54c84756f0c7a9ddaf704f68e145a Mon Sep 17 00:00:00 2001 From: Rob Day-Reynolds Date: Thu, 18 Jul 2019 12:44:52 -0700 Subject: [PATCH 1/3] Add ability to pass ssh socket heartbeat interval When running multiple concurrent deployments over SSH with ruby threads, a race condition can occur where a docker operation reads all data from the forwarded socket before net/ssh can check for readability on the socket with IO.select. Setting an ssh.loop `wait` ensures that the Docker operation block passed to ssh.loop is evaluated at least once per `wait`. Co-authored-by: Christina Guida Co-authored-by: Rob Day-Reynolds Co-authored-by: Stephen Weber --- README.md | 1 + lib/centurion/deploy_dsl.rb | 1 + lib/centurion/docker_via_api.rb | 5 ++--- lib/centurion/docker_via_cli.rb | 2 +- lib/centurion/ssh.rb | 4 ++-- spec/docker_via_api_spec.rb | 18 +++++++++++++++--- spec/docker_via_cli_spec.rb | 20 ++++++++++++++++---- 7 files changed, 38 insertions(+), 13 deletions(-) diff --git a/README.md b/README.md index b080d9b7..c6855530 100644 --- a/README.md +++ b/README.md @@ -401,6 +401,7 @@ You can configure it with a few options: set :ssh, true # enable ssh connections set :ssh_user, "myuser" # if you want to specify the user to connect as, otherwise your current user set :ssh_log_level, Logger::DEBUG # passed on to net/ssh, can be noisy; defaults to Logger::WARN + set :ssh_socket_heartbeat, 5 # passed on to net/ssh (Net::SSH::Connection::Session#loop); defaults to nil end ``` diff --git a/lib/centurion/deploy_dsl.rb b/lib/centurion/deploy_dsl.rb index 620db9ef..d437bf6a 100644 --- a/lib/centurion/deploy_dsl.rb +++ b/lib/centurion/deploy_dsl.rb @@ -195,6 +195,7 @@ def build_server_params # nil is OK for both of these, defaults applied internally opts[:ssh_user] = fetch(:ssh_user) opts[:ssh_log_level] = fetch(:ssh_log_level) + opts[:ssh_socket_heartbeat] = fetch(:ssh_socket_heartbeat) end opts diff --git a/lib/centurion/docker_via_api.rb b/lib/centurion/docker_via_api.rb index eee9e603..447468c0 100644 --- a/lib/centurion/docker_via_api.rb +++ b/lib/centurion/docker_via_api.rb @@ -12,8 +12,7 @@ def initialize(hostname, port, connection_opts = {}, api_version = nil) if connection_opts[:ssh] @base_uri = hostname @ssh = true - @ssh_user = connection_opts[:ssh_user] - @ssh_log_level = connection_opts[:ssh_log_level] + @connection_opts = connection_opts else @base_uri = "http#{'s' if tls_enable?}://#{hostname}:#{port}" end @@ -194,7 +193,7 @@ def with_excon(&block) end def with_excon_via_ssh - Centurion::SSH.with_docker_socket(@base_uri, @ssh_user, @ssh_log_level) do |socket| + Centurion::SSH.with_docker_socket(@base_uri, @connection_opts[:ssh_user], @connection_opts[:ssh_log_level], @connection_opts[:ssh_socket_heartbeat]) do |socket| conn = Excon.new('unix:///', socket: socket) yield conn end diff --git a/lib/centurion/docker_via_cli.rb b/lib/centurion/docker_via_cli.rb index 636d84e9..0dab600b 100644 --- a/lib/centurion/docker_via_cli.rb +++ b/lib/centurion/docker_via_cli.rb @@ -97,7 +97,7 @@ def build_command(action, destination) def connect if @connection_opts[:ssh] - Centurion::SSH.with_docker_socket(@docker_host, @connection_opts[:ssh_user], @connection_opts[:ssh_log_level]) do |socket| + Centurion::SSH.with_docker_socket(@docker_host, @connection_opts[:ssh_user], @connection_opts[:ssh_log_level], @connection_opts[:ssh_socket_heartbeat]) do |socket| @socket = socket ret = yield @socket = nil diff --git a/lib/centurion/ssh.rb b/lib/centurion/ssh.rb index 20cc908c..bb6e8b4a 100644 --- a/lib/centurion/ssh.rb +++ b/lib/centurion/ssh.rb @@ -7,7 +7,7 @@ module Centurion; end module Centurion::SSH extend self - def with_docker_socket(hostname, user, log_level = nil) + def with_docker_socket(hostname, user, log_level = nil, ssh_socket_heartbeat = nil) log_level ||= Logger::WARN with_sshkit(hostname, user) do @@ -24,7 +24,7 @@ def with_docker_socket(hostname, user, log_level = nil) yield local_socket_path end - ssh.loop { t.alive? } + ssh.loop(ssh_socket_heartbeat) { t.alive? } ssh.forward.cancel_local_socket local_socket_path local_socket_path_file.delete t.value diff --git a/spec/docker_via_api_spec.rb b/spec/docker_via_api_spec.rb index 5399e1e2..03803b0d 100644 --- a/spec/docker_via_api_spec.rb +++ b/spec/docker_via_api_spec.rb @@ -134,6 +134,7 @@ let(:port) { nil } let(:ssh_user) { 'myuser' } let(:ssh_log_level) { nil } + let(:ssh_socket_heartbeat) { nil } let(:base_req) { { socket: '/tmp/socket/path' } } @@ -142,12 +143,13 @@ p = { ssh: true} p[:ssh_user] = ssh_user if ssh_user p[:ssh_log_level] = ssh_log_level if ssh_log_level + p[:ssh_socket_heartbeat] = ssh_socket_heartbeat if ssh_socket_heartbeat p end context 'with no log level' do before do - expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, ssh_user, nil).and_yield('/tmp/socket/path') + expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, ssh_user, nil, nil).and_yield('/tmp/socket/path') end it_behaves_like 'docker API' @@ -157,7 +159,7 @@ let(:ssh_user) { nil } before do - expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, nil, nil).and_yield('/tmp/socket/path') + expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, nil, nil, nil).and_yield('/tmp/socket/path') end it_behaves_like 'docker API' @@ -167,7 +169,17 @@ let(:ssh_log_level) { Logger::DEBUG } before do - expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, ssh_user, Logger::DEBUG).and_yield('/tmp/socket/path') + expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, ssh_user, Logger::DEBUG, nil).and_yield('/tmp/socket/path') + end + + it_behaves_like 'docker API' + end + + context 'with a socket heartbeat set' do + let(:ssh_socket_heartbeat) { 5 } + + before do + expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, ssh_user, nil, 5).and_yield('/tmp/socket/path') end it_behaves_like 'docker API' diff --git a/spec/docker_via_cli_spec.rb b/spec/docker_via_cli_spec.rb index 1a5632cd..0c5ec77e 100644 --- a/spec/docker_via_cli_spec.rb +++ b/spec/docker_via_cli_spec.rb @@ -69,18 +69,20 @@ let(:hostname) { 'host1' } let(:ssh_user) { 'myuser' } let(:ssh_log_level) { nil } + let(:ssh_socket_heartbeat) { nil } let(:docker_via_cli) { Centurion::DockerViaCli.new(hostname, nil, docker_path, params) } let(:prefix) { "-H=unix:///tmp/socket/path" } let(:params) do - p = { ssh: true} + p = { ssh: true } p[:ssh_user] = ssh_user if ssh_user p[:ssh_log_level] = ssh_log_level if ssh_log_level + p[:ssh_socket_heartbeat] = ssh_socket_heartbeat if ssh_socket_heartbeat p end context 'with no log level' do before do - expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, ssh_user, nil).and_yield('/tmp/socket/path') + expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, ssh_user, nil, nil).and_yield('/tmp/socket/path') end it_behaves_like 'docker CLI' @@ -90,7 +92,7 @@ let(:ssh_user) { nil } before do - expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, nil, nil).and_yield('/tmp/socket/path') + expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, nil, nil, nil).and_yield('/tmp/socket/path') end it_behaves_like 'docker CLI' @@ -100,7 +102,17 @@ let(:ssh_log_level) { Logger::DEBUG } before do - expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, ssh_user, Logger::DEBUG).and_yield('/tmp/socket/path') + expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, ssh_user, Logger::DEBUG, nil).and_yield('/tmp/socket/path') + end + + it_behaves_like 'docker CLI' + end + + context 'with an ssh loop wait set' do + let(:ssh_socket_heartbeat) { 5 } + + before do + expect(Centurion::SSH).to receive(:with_docker_socket).with(hostname, ssh_user, nil, 5).and_yield('/tmp/socket/path') end it_behaves_like 'docker CLI' From 2278c1f12bd16824c317dc301ce1b4eb5e79e611 Mon Sep 17 00:00:00 2001 From: Drew Stokes Date: Fri, 19 Jul 2019 15:57:06 -0700 Subject: [PATCH 2/3] set ssh_socket_heartbeat default to 30s --- README.md | 2 +- lib/centurion/ssh.rb | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/README.md b/README.md index c6855530..98046bf6 100644 --- a/README.md +++ b/README.md @@ -401,7 +401,7 @@ You can configure it with a few options: set :ssh, true # enable ssh connections set :ssh_user, "myuser" # if you want to specify the user to connect as, otherwise your current user set :ssh_log_level, Logger::DEBUG # passed on to net/ssh, can be noisy; defaults to Logger::WARN - set :ssh_socket_heartbeat, 5 # passed on to net/ssh (Net::SSH::Connection::Session#loop); defaults to nil + set :ssh_socket_heartbeat, 5 # passed on to net/ssh (Net::SSH::Connection::Session#loop); defaults to 30 end ``` diff --git a/lib/centurion/ssh.rb b/lib/centurion/ssh.rb index bb6e8b4a..1e8530b7 100644 --- a/lib/centurion/ssh.rb +++ b/lib/centurion/ssh.rb @@ -7,7 +7,7 @@ module Centurion; end module Centurion::SSH extend self - def with_docker_socket(hostname, user, log_level = nil, ssh_socket_heartbeat = nil) + def with_docker_socket(hostname, user, log_level = nil, ssh_socket_heartbeat = 30) log_level ||= Logger::WARN with_sshkit(hostname, user) do From 6a05fe229dd54a5b30bd6e9b18cf864048b86175 Mon Sep 17 00:00:00 2001 From: Stephen Weber Date: Fri, 19 Jul 2019 16:55:14 -0700 Subject: [PATCH 3/3] add documentation on troubleshooting with ssh_socket_heartbeat --- README.md | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/README.md b/README.md index 98046bf6..0bbee57d 100644 --- a/README.md +++ b/README.md @@ -405,6 +405,16 @@ You can configure it with a few options: end ``` +#### Troubleshooting SSH connections + +In some cases you may notice your SSH commands are completing successfully, +but the connection isn't aware they are done. This will manifest as a tunneled +command taking much longer than anticipated - minutes depending on your +server's configuration. You may need to set `:ssh_socket_heartbeat` to a +smaller number. This will check more frequently if the command has completed +which can alleviate this issue, though it will consume more CPU as it wakes up +its threads more frequently. + Deploying ---------