Closed rajsahae closed 10 years ago
I have a similar issue with a tarball which is greater than 10MB
Any new about this?
Not as far as I know.
I can try looking into the Net::SSH source to see what's going on but it's going to take me a while to get to it and once I start looking, some time to get up to speed to figure out how it works.
I did find this post in the HoneyBadger gem where they fixed a similar exception as a concurrency race condition: https://github.com/honeybadger-io/honeybadger-ruby/issues/64
more details in this post, same honeybadger issue: https://github.com/honeybadger-io/honeybadger-ruby/issues/60
They had some concurrent writes happening to a hash. They locked the writes to fix the issue. Not sure if this is our problem. Will need to investigate what hash is having problems and how it's used.
This gem uses concurrency and also hits this exception: https://github.com/kovyrin/db-charmer/issues/90
In some of the discussion related to the db-charmer gem, I found this post in the rails gem which complains about the Hash#each_value method. https://github.com/rails/rails/pull/14151
I also googled to find this blog post which discusses a case in ruby where you iterate through a Hash while modifying it and that can raise this exception: http://jdfrens.blogspot.com/2013/04/cant-add-new-key-into-hash-during.html
Just some things to look for.
As far as I can tell, the Net::SSH gem isn't using concurrency. The point of the exception is in the open_channel method but it's not doing anything super complicated. I'll add some debug exception handling code to my ssh gem and I'll run some real world cases to try and see what comes from it.
Here is the modification I made:
def open_channel(type="session", *extra, &on_confirm)
local_id = get_next_channel_id
channel = Channel.new(self, type, local_id, @max_pkt_size, @max_win_size, &on_confirm)
msg = Buffer.from(:byte, CHANNEL_OPEN, :string, type, :long, local_id,
:long, channel.local_maximum_window_size,
:long, channel.local_maximum_packet_size, *extra)
send_message(msg)
begin
channels[local_id] = channel
rescue RuntimeError => run_time_error
if run_time_error.message.match /can't add a new key into hash during iteration/
p channels
p channels.size
p channels.keys.size
p channels.keys
p channels.values.size
p channels.values
end
raise run_time_error
end
end
and here is the output I got when it failed (failed at roughly 20 MB of a 70 MB download)
Progress: 6963200/69348500 - 10%
Progress: 13877248/69348500 - 20%
Progress: 20824064/69348500 - 30%
{3=>#<Net::SSH::Connection::Channel:0x000000019dbba0 @logger=#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>, @connection=#<Net::SSH::Connection::Session:0x0000000212d868 @logger=#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>, @transport=#<Net::SSH::Transport::Session:0x000000020c6af0 @logger=#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>, @host="172.18.1.94", @port=22, @bind_address=nil, @options={:send_env=>[/^LANG$/, /^LC_CTYPE$/, /^LC_NUMERIC$/, /^LC_TIME$/, /^LC_COLLATE$/, /^LC_MONETARY$/, /^LC_MESSAGES$/], :password=>"4ed041a3a9ffe042", :user=>"tesla1", :logger=>#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>}, @socket=#<TCPSocket:fd 5>, @queue=[], @host_key_verifier=#<Net::SSH::Verifiers::Lenient:0x000000020ce048>, @server_version=#<Net::SSH::Transport::ServerVersion:0x000000020cdfd0 @header="", @version="SSH-2.0-OpenSSH_5.5p1 Debian-4ubuntu4", @logger=#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>>, @host_as_string="172.18.1.94", @algorithms=#<Net::SSH::Transport::Algorithms:0x000000020cc900 @session=#<Net::SSH::Transport::Session:0x000000020c6af0 ...>, @logger=#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>, @options={:send_env=>[/^LANG$/, /^LC_CTYPE$/, /^LC_NUMERIC$/, /^LC_TIME$/, /^LC_COLLATE$/, /^LC_MONETARY$/, /^LC_MESSAGES$/], :password=>"4ed041a3a9ffe042", :user=>"tesla1", :logger=>#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>}, @algorithms={:host_key=>["ssh-rsa", "ssh-dss"], :kex=>["diffie-hellman-group-exchange-sha1", "diffie-hellman-group1-sha1", "diffie-hellman-group14-sha1", "diffie-hellman-group-exchange-sha256"], :encryption=>["aes128-cbc", "3des-cbc", "blowfish-cbc", "cast128-cbc", "aes192-cbc", "aes256-cbc", "rijndael-cbc@lysator.liu.se", "idea-cbc", "none", "arcfour128", "arcfour256", "arcfour", "aes128-ctr", "aes192-ctr", "aes256-ctr", "camellia128-cbc", "camellia192-cbc", "camellia256-cbc", "camellia128-cbc@openssh.org", "camellia192-cbc@openssh.org", "camellia256-cbc@openssh.org", "camellia128-ctr", "camellia192-ctr", "camellia256-ctr", "camellia128-ctr@openssh.org", "camellia192-ctr@openssh.org", "camellia256-ctr@openssh.org", "cast128-ctr", "blowfish-ctr", "3des-ctr"], :hmac=>["hmac-sha1", "hmac-md5", "hmac-sha1-96", "hmac-md5-96", "hmac-ripemd160", "hmac-ripemd160@openssh.com", "hmac-sha2-256", "hmac-sha2-512", "hmac-sha2-256-96", "hmac-sha2-512-96", "none"], :compression=>["none", "zlib@openssh.com", "zlib"], :language=>[], :encryption_server=>["aes128-cbc", "3des-cbc", "blowfish-cbc", "cast128-cbc", "aes192-cbc", "aes256-cbc", "rijndael-cbc@lysator.liu.se", "idea-cbc", "none", "arcfour128", "arcfour256", "arcfour", "aes128-ctr", "aes192-ctr", "aes256-ctr", "camellia128-cbc", "camellia192-cbc", "camellia256-cbc", "camellia128-cbc@openssh.org", "camellia192-cbc@openssh.org", "camellia256-cbc@openssh.org", "camellia128-ctr", "camellia192-ctr", "camellia256-ctr", "camellia128-ctr@openssh.org", "camellia192-ctr@openssh.org", "camellia256-ctr@openssh.org", "cast128-ctr", "blowfish-ctr", "3des-ctr"], :encryption_client=>["aes128-cbc", "3des-cbc", "blowfish-cbc", "cast128-cbc", "aes192-cbc", "aes256-cbc", "rijndael-cbc@lysator.liu.se", "idea-cbc", "none", "arcfour128", "arcfour256", "arcfour", "aes128-ctr", "aes192-ctr", "aes256-ctr", "camellia128-cbc", "camellia192-cbc", "camellia256-cbc", "camellia128-cbc@openssh.org", "camellia192-cbc@openssh.org", "camellia256-cbc@openssh.org", "camellia128-ctr", "camellia192-ctr", "camellia256-ctr", "camellia128-ctr@openssh.org", "camellia192-ctr@openssh.org", "camellia256-ctr@openssh.org", "cast128-ctr", "blowfish-ctr", "3des-ctr"], :hmac_server=>["hmac-sha1", "hmac-md5", "hmac-sha1-96", "hmac-md5-96", "hmac-ripemd160", "hmac-ripemd160@openssh.com", "hmac-sha2-256", "hmac-sha2-512", "hmac-sha2-256-96", "hmac-sha2-512-96", "none"], :hmac_client=>["hmac-sha1", "hmac-md5", "hmac-sha1-96", "hmac-md5-96", "hmac-ripemd160", "hmac-ripemd160@openssh.com", "hmac-sha2-256", "hmac-sha2-512", "hmac-sha2-256-96", "hmac-sha2-512-96", "none"], :compression_server=>["none", "zlib@openssh.com", "zlib"], :compression_client=>["none", "zlib@openssh.com", "zlib"], :language_server=>[], :language_client=>[]}, @initialized=true, @pending=false, @server_packet="\x14\xB9R A+a\xC8\xEA\x1C*#\xB9\x15\x9D\xF9\xFB\x00\x00\x00~diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1\x00\x00\x00\x0Fssh-rsa,ssh-dss\x00\x00\x00\x9Daes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se\x00\x00\x00\x9Daes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se\x00\x00\x00ihmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96\x00\x00\x00ihmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96\x00\x00\x00\x15none,zlib@openssh.com\x00\x00\x00\x15none,zlib@openssh.com\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00", @client_packet="\x14\xB4\xDA\x14\xA0M\xC4\xB8&\x03\xF7\x0Fn\xFD\xAF\x83\xD3\x00\x00\x00~diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1,diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha256\x00\x00\x00\x0Fssh-rsa,ssh-dss\x00\x00\x01\xD5aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,idea-cbc,none,arcfour128,arcfour256,arcfour,aes128-ctr,aes192-ctr,aes256-ctr,camellia128-cbc,camellia192-cbc,camellia256-cbc,camellia128-cbc@openssh.org,camellia192-cbc@openssh.org,camellia256-cbc@openssh.org,camellia128-ctr,camellia192-ctr,camellia256-ctr,camellia128-ctr@openssh.org,camellia192-ctr@openssh.org,camellia256-ctr@openssh.org,cast128-ctr,blowfish-ctr,3des-ctr\x00\x00\x01\xD5aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,idea-cbc,none,arcfour128,arcfour256,arcfour,aes128-ctr,aes192-ctr,aes256-ctr,camellia128-cbc,camellia192-cbc,camellia256-cbc,camellia128-cbc@openssh.org,camellia192-cbc@openssh.org,camellia256-cbc@openssh.org,camellia128-ctr,camellia192-ctr,camellia256-ctr,camellia128-ctr@openssh.org,camellia192-ctr@openssh.org,camellia256-ctr@openssh.org,cast128-ctr,blowfish-ctr,3des-ctr\x00\x00\x00\x98hmac-sha1,hmac-md5,hmac-sha1-96,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha2-256-96,hmac-sha2-512-96,none\x00\x00\x00\x98hmac-sha1,hmac-md5,hmac-sha1-96,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha2-256-96,hmac-sha2-512-96,none\x00\x00\x00\x1Anone,zlib@openssh.com,zlib\x00\x00\x00\x1Anone,zlib@openssh.com,zlib\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00", @server_data={:raw=>"\x14\xB9R A+a\xC8\xEA\x1C*#\xB9\x15\x9D\xF9\xFB\x00\x00\x00~diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1\x00\x00\x00\x0Fssh-rsa,ssh-dss\x00\x00\x00\x9Daes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se\x00\x00\x00\x9Daes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se\x00\x00\x00ihmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96\x00\x00\x00ihmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96\x00\x00\x00\x15none,zlib@openssh.com\x00\x00\x00\x15none,zlib@openssh.com\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00", :kex=>["diffie-hellman-group-exchange-sha256", "diffie-hellman-group-exchange-sha1", "diffie-hellman-group14-sha1", "diffie-hellman-group1-sha1"], :host_key=>["ssh-rsa", "ssh-dss"], :encryption_client=>["aes128-ctr", "aes192-ctr", "aes256-ctr", "arcfour256", "arcfour128", "aes128-cbc", "3des-cbc", "blowfish-cbc", "cast128-cbc", "aes192-cbc", "aes256-cbc", "arcfour", "rijndael-cbc@lysator.liu.se"], :encryption_server=>["aes128-ctr", "aes192-ctr", "aes256-ctr", "arcfour256", "arcfour128", "aes128-cbc", "3des-cbc", "blowfish-cbc", "cast128-cbc", "aes192-cbc", "aes256-cbc", "arcfour", "rijndael-cbc@lysator.liu.se"], :hmac_client=>["hmac-md5", "hmac-sha1", "umac-64@openssh.com", "hmac-ripemd160", "hmac-ripemd160@openssh.com", "hmac-sha1-96", "hmac-md5-96"], :hmac_server=>["hmac-md5", "hmac-sha1", "umac-64@openssh.com", "hmac-ripemd160", "hmac-ripemd160@openssh.com", "hmac-sha1-96", "hmac-md5-96"], :compression_client=>["none", "zlib@openssh.com"], :compression_server=>["none", "zlib@openssh.com"], :language_client=>[], :language_server=>[]}, @kex="diffie-hellman-group-exchange-sha1", @host_key="ssh-rsa", @encryption_client="aes128-cbc", @encryption_server="aes128-cbc", @hmac_client="hmac-sha1", @hmac_server="hmac-sha1", @compression_client="none", @compression_server="none", @language_client="", @language_server="", @session_id="\xDE@(\x9F\xFF\r\x89\x93u<\xC1\t\r:\x9C=\xA5g\xCD\xD6">>, @options={:send_env=>[/^LANG$/, /^LC_CTYPE$/, /^LC_NUMERIC$/, /^LC_TIME$/, /^LC_COLLATE$/, /^LC_MONETARY$/, /^LC_MESSAGES$/], :password=>"4ed041a3a9ffe042", :user=>"tesla1", :logger=>#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>}, @channel_id_counter=4, @channels={...}, @listeners={#<TCPSocket:fd 5>=>nil}, @pending_requests=[], @channel_open_handlers={}, @on_global_request={}, @properties={}, @max_pkt_size=32768, @max_win_size=131072, @last_keepalive_sent_at=nil, @scp=#<Net::SCP:0x00000002133858 @session=#<Net::SSH::Connection::Session:0x0000000212d868 ...>, @logger=#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>>>, @type="session", @local_id=3, @local_maximum_packet_size=32768, @local_maximum_window_size=43122688, @local_window_size=21577691, @on_confirm_open=#<Proc:0x000000019dbbf0@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-scp-1.1.2/lib/net/scp.rb:340>, @output=, @properties={:local=>#<StringIO:0x000000019dbc90>, :remote=>"/tmp/grablogs_download.tgz", :options=>{}, :callback=>#<Proc:0x000000019dbce0@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/jump_scripts-1.6.6/lib/jump_scripts/log_grabber.rb:178>, :buffer=>, :state=>:read_data, :stack=>[], :file=>{:type=>:file, :mode=>420, :size=>69348500, :name=>"grablogs_download.tgz", :times=>nil}, :io=>#<StringIO:0x000000019dbc90>, :times=>nil, :remaining=>47803540}, @pending_requests=[], @on_eof=nil, @on_close=#<Proc:0x000000015b78a8@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-scp-1.1.2/lib/net/scp.rb:359>, @on_process=#<Proc:0x000000015b7790@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-scp-1.1.2/lib/net/scp.rb:363>, @on_extended_data=#<Proc:0x000000015b7858@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-scp-1.1.2/lib/net/scp.rb:361>, @on_data=#<Proc:0x000000015b7880@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-scp-1.1.2/lib/net/scp.rb:360>, @on_open_failed=nil, @on_request={"exit-status"=>#<Proc:0x000000015b7808@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-scp-1.1.2/lib/net/scp.rb:362>}, @sent_eof=false, @eof=false, @closing=false, @remote_id=1, @remote_maximum_window_size=2097152, @remote_window_size=2097150, @remote_maximum_packet_size=32768>}
1
1
[3]
1
[#<Net::SSH::Connection::Channel:0x000000019dbba0 @logger=#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>, @connection=#<Net::SSH::Connection::Session:0x0000000212d868 @logger=#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>, @transport=#<Net::SSH::Transport::Session:0x000000020c6af0 @logger=#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>, @host="172.18.1.94", @port=22, @bind_address=nil, @options={:send_env=>[/^LANG$/, /^LC_CTYPE$/, /^LC_NUMERIC$/, /^LC_TIME$/, /^LC_COLLATE$/, /^LC_MONETARY$/, /^LC_MESSAGES$/], :password=>"4ed041a3a9ffe042", :user=>"tesla1", :logger=>#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>}, @socket=#<TCPSocket:fd 5>, @queue=[], @host_key_verifier=#<Net::SSH::Verifiers::Lenient:0x000000020ce048>, @server_version=#<Net::SSH::Transport::ServerVersion:0x000000020cdfd0 @header="", @version="SSH-2.0-OpenSSH_5.5p1 Debian-4ubuntu4", @logger=#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>>, @host_as_string="172.18.1.94", @algorithms=#<Net::SSH::Transport::Algorithms:0x000000020cc900 @session=#<Net::SSH::Transport::Session:0x000000020c6af0 ...>, @logger=#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>, @options={:send_env=>[/^LANG$/, /^LC_CTYPE$/, /^LC_NUMERIC$/, /^LC_TIME$/, /^LC_COLLATE$/, /^LC_MONETARY$/, /^LC_MESSAGES$/], :password=>"4ed041a3a9ffe042", :user=>"tesla1", :logger=>#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>}, @algorithms={:host_key=>["ssh-rsa", "ssh-dss"], :kex=>["diffie-hellman-group-exchange-sha1", "diffie-hellman-group1-sha1", "diffie-hellman-group14-sha1", "diffie-hellman-group-exchange-sha256"], :encryption=>["aes128-cbc", "3des-cbc", "blowfish-cbc", "cast128-cbc", "aes192-cbc", "aes256-cbc", "rijndael-cbc@lysator.liu.se", "idea-cbc", "none", "arcfour128", "arcfour256", "arcfour", "aes128-ctr", "aes192-ctr", "aes256-ctr", "camellia128-cbc", "camellia192-cbc", "camellia256-cbc", "camellia128-cbc@openssh.org", "camellia192-cbc@openssh.org", "camellia256-cbc@openssh.org", "camellia128-ctr", "camellia192-ctr", "camellia256-ctr", "camellia128-ctr@openssh.org", "camellia192-ctr@openssh.org", "camellia256-ctr@openssh.org", "cast128-ctr", "blowfish-ctr", "3des-ctr"], :hmac=>["hmac-sha1", "hmac-md5", "hmac-sha1-96", "hmac-md5-96", "hmac-ripemd160", "hmac-ripemd160@openssh.com", "hmac-sha2-256", "hmac-sha2-512", "hmac-sha2-256-96", "hmac-sha2-512-96", "none"], :compression=>["none", "zlib@openssh.com", "zlib"], :language=>[], :encryption_server=>["aes128-cbc", "3des-cbc", "blowfish-cbc", "cast128-cbc", "aes192-cbc", "aes256-cbc", "rijndael-cbc@lysator.liu.se", "idea-cbc", "none", "arcfour128", "arcfour256", "arcfour", "aes128-ctr", "aes192-ctr", "aes256-ctr", "camellia128-cbc", "camellia192-cbc", "camellia256-cbc", "camellia128-cbc@openssh.org", "camellia192-cbc@openssh.org", "camellia256-cbc@openssh.org", "camellia128-ctr", "camellia192-ctr", "camellia256-ctr", "camellia128-ctr@openssh.org", "camellia192-ctr@openssh.org", "camellia256-ctr@openssh.org", "cast128-ctr", "blowfish-ctr", "3des-ctr"], :encryption_client=>["aes128-cbc", "3des-cbc", "blowfish-cbc", "cast128-cbc", "aes192-cbc", "aes256-cbc", "rijndael-cbc@lysator.liu.se", "idea-cbc", "none", "arcfour128", "arcfour256", "arcfour", "aes128-ctr", "aes192-ctr", "aes256-ctr", "camellia128-cbc", "camellia192-cbc", "camellia256-cbc", "camellia128-cbc@openssh.org", "camellia192-cbc@openssh.org", "camellia256-cbc@openssh.org", "camellia128-ctr", "camellia192-ctr", "camellia256-ctr", "camellia128-ctr@openssh.org", "camellia192-ctr@openssh.org", "camellia256-ctr@openssh.org", "cast128-ctr", "blowfish-ctr", "3des-ctr"], :hmac_server=>["hmac-sha1", "hmac-md5", "hmac-sha1-96", "hmac-md5-96", "hmac-ripemd160", "hmac-ripemd160@openssh.com", "hmac-sha2-256", "hmac-sha2-512", "hmac-sha2-256-96", "hmac-sha2-512-96", "none"], :hmac_client=>["hmac-sha1", "hmac-md5", "hmac-sha1-96", "hmac-md5-96", "hmac-ripemd160", "hmac-ripemd160@openssh.com", "hmac-sha2-256", "hmac-sha2-512", "hmac-sha2-256-96", "hmac-sha2-512-96", "none"], :compression_server=>["none", "zlib@openssh.com", "zlib"], :compression_client=>["none", "zlib@openssh.com", "zlib"], :language_server=>[], :language_client=>[]}, @initialized=true, @pending=false, @server_packet="\x14\xB9R A+a\xC8\xEA\x1C*#\xB9\x15\x9D\xF9\xFB\x00\x00\x00~diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1\x00\x00\x00\x0Fssh-rsa,ssh-dss\x00\x00\x00\x9Daes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se\x00\x00\x00\x9Daes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se\x00\x00\x00ihmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96\x00\x00\x00ihmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96\x00\x00\x00\x15none,zlib@openssh.com\x00\x00\x00\x15none,zlib@openssh.com\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00", @client_packet="\x14\xB4\xDA\x14\xA0M\xC4\xB8&\x03\xF7\x0Fn\xFD\xAF\x83\xD3\x00\x00\x00~diffie-hellman-group-exchange-sha1,diffie-hellman-group1-sha1,diffie-hellman-group14-sha1,diffie-hellman-group-exchange-sha256\x00\x00\x00\x0Fssh-rsa,ssh-dss\x00\x00\x01\xD5aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,idea-cbc,none,arcfour128,arcfour256,arcfour,aes128-ctr,aes192-ctr,aes256-ctr,camellia128-cbc,camellia192-cbc,camellia256-cbc,camellia128-cbc@openssh.org,camellia192-cbc@openssh.org,camellia256-cbc@openssh.org,camellia128-ctr,camellia192-ctr,camellia256-ctr,camellia128-ctr@openssh.org,camellia192-ctr@openssh.org,camellia256-ctr@openssh.org,cast128-ctr,blowfish-ctr,3des-ctr\x00\x00\x01\xD5aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,rijndael-cbc@lysator.liu.se,idea-cbc,none,arcfour128,arcfour256,arcfour,aes128-ctr,aes192-ctr,aes256-ctr,camellia128-cbc,camellia192-cbc,camellia256-cbc,camellia128-cbc@openssh.org,camellia192-cbc@openssh.org,camellia256-cbc@openssh.org,camellia128-ctr,camellia192-ctr,camellia256-ctr,camellia128-ctr@openssh.org,camellia192-ctr@openssh.org,camellia256-ctr@openssh.org,cast128-ctr,blowfish-ctr,3des-ctr\x00\x00\x00\x98hmac-sha1,hmac-md5,hmac-sha1-96,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha2-256-96,hmac-sha2-512-96,none\x00\x00\x00\x98hmac-sha1,hmac-md5,hmac-sha1-96,hmac-md5-96,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha2-256,hmac-sha2-512,hmac-sha2-256-96,hmac-sha2-512-96,none\x00\x00\x00\x1Anone,zlib@openssh.com,zlib\x00\x00\x00\x1Anone,zlib@openssh.com,zlib\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00", @server_data={:raw=>"\x14\xB9R A+a\xC8\xEA\x1C*#\xB9\x15\x9D\xF9\xFB\x00\x00\x00~diffie-hellman-group-exchange-sha256,diffie-hellman-group-exchange-sha1,diffie-hellman-group14-sha1,diffie-hellman-group1-sha1\x00\x00\x00\x0Fssh-rsa,ssh-dss\x00\x00\x00\x9Daes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se\x00\x00\x00\x9Daes128-ctr,aes192-ctr,aes256-ctr,arcfour256,arcfour128,aes128-cbc,3des-cbc,blowfish-cbc,cast128-cbc,aes192-cbc,aes256-cbc,arcfour,rijndael-cbc@lysator.liu.se\x00\x00\x00ihmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96\x00\x00\x00ihmac-md5,hmac-sha1,umac-64@openssh.com,hmac-ripemd160,hmac-ripemd160@openssh.com,hmac-sha1-96,hmac-md5-96\x00\x00\x00\x15none,zlib@openssh.com\x00\x00\x00\x15none,zlib@openssh.com\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00", :kex=>["diffie-hellman-group-exchange-sha256", "diffie-hellman-group-exchange-sha1", "diffie-hellman-group14-sha1", "diffie-hellman-group1-sha1"], :host_key=>["ssh-rsa", "ssh-dss"], :encryption_client=>["aes128-ctr", "aes192-ctr", "aes256-ctr", "arcfour256", "arcfour128", "aes128-cbc", "3des-cbc", "blowfish-cbc", "cast128-cbc", "aes192-cbc", "aes256-cbc", "arcfour", "rijndael-cbc@lysator.liu.se"], :encryption_server=>["aes128-ctr", "aes192-ctr", "aes256-ctr", "arcfour256", "arcfour128", "aes128-cbc", "3des-cbc", "blowfish-cbc", "cast128-cbc", "aes192-cbc", "aes256-cbc", "arcfour", "rijndael-cbc@lysator.liu.se"], :hmac_client=>["hmac-md5", "hmac-sha1", "umac-64@openssh.com", "hmac-ripemd160", "hmac-ripemd160@openssh.com", "hmac-sha1-96", "hmac-md5-96"], :hmac_server=>["hmac-md5", "hmac-sha1", "umac-64@openssh.com", "hmac-ripemd160", "hmac-ripemd160@openssh.com", "hmac-sha1-96", "hmac-md5-96"], :compression_client=>["none", "zlib@openssh.com"], :compression_server=>["none", "zlib@openssh.com"], :language_client=>[], :language_server=>[]}, @kex="diffie-hellman-group-exchange-sha1", @host_key="ssh-rsa", @encryption_client="aes128-cbc", @encryption_server="aes128-cbc", @hmac_client="hmac-sha1", @hmac_server="hmac-sha1", @compression_client="none", @compression_server="none", @language_client="", @language_server="", @session_id="\xDE@(\x9F\xFF\r\x89\x93u<\xC1\t\r:\x9C=\xA5g\xCD\xD6">>, @options={:send_env=>[/^LANG$/, /^LC_CTYPE$/, /^LC_NUMERIC$/, /^LC_TIME$/, /^LC_COLLATE$/, /^LC_MONETARY$/, /^LC_MESSAGES$/], :password=>"4ed041a3a9ffe042", :user=>"tesla1", :logger=>#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>}, @channel_id_counter=4, @channels={3=>#<Net::SSH::Connection::Channel:0x000000019dbba0 ...>}, @listeners={#<TCPSocket:fd 5>=>nil}, @pending_requests=[], @channel_open_handlers={}, @on_global_request={}, @properties={}, @max_pkt_size=32768, @max_win_size=131072, @last_keepalive_sent_at=nil, @scp=#<Net::SCP:0x00000002133858 @session=#<Net::SSH::Connection::Session:0x0000000212d868 ...>, @logger=#<Logger:0x000000020c6cd0 @progname=nil, @level=4, @default_formatter=#<Logger::Formatter:0x000000020c6ca8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000020c6c30 @shift_size=nil, @shift_age=nil, @filename=nil, @dev=#<IO:<STDERR>>, @mutex=#<Logger::LogDevice::LogDeviceMutex:0x000000020c6c08 @mon_owner=nil, @mon_count=0, @mon_mutex=#<Mutex:0x000000020c6b18>>>>>>, @type="session", @local_id=3, @local_maximum_packet_size=32768, @local_maximum_window_size=43122688, @local_window_size=21577691, @on_confirm_open=#<Proc:0x000000019dbbf0@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-scp-1.1.2/lib/net/scp.rb:340>, @output=, @properties={:local=>#<StringIO:0x000000019dbc90>, :remote=>"/tmp/grablogs_download.tgz", :options=>{}, :callback=>#<Proc:0x000000019dbce0@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/jump_scripts-1.6.6/lib/jump_scripts/log_grabber.rb:178>, :buffer=>, :state=>:read_data, :stack=>[], :file=>{:type=>:file, :mode=>420, :size=>69348500, :name=>"grablogs_download.tgz", :times=>nil}, :io=>#<StringIO:0x000000019dbc90>, :times=>nil, :remaining=>47803540}, @pending_requests=[], @on_eof=nil, @on_close=#<Proc:0x000000015b78a8@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-scp-1.1.2/lib/net/scp.rb:359>, @on_process=#<Proc:0x000000015b7790@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-scp-1.1.2/lib/net/scp.rb:363>, @on_extended_data=#<Proc:0x000000015b7858@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-scp-1.1.2/lib/net/scp.rb:361>, @on_data=#<Proc:0x000000015b7880@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-scp-1.1.2/lib/net/scp.rb:360>, @on_open_failed=nil, @on_request={"exit-status"=>#<Proc:0x000000015b7808@/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-scp-1.1.2/lib/net/scp.rb:362>}, @sent_eof=false, @eof=false, @closing=false, @remote_id=1, @remote_maximum_window_size=2097152, @remote_window_size=2097150, @remote_maximum_packet_size=32768>]
/home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:306:in `[]=': can't add a new key into hash during iteration (RuntimeError)
from /home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:306:in `open_channel'
from /home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:341:in `exec'
from /home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:375:in `exec!'
from /home/eng-sa/.rvm/gems/ruby-1.9.3-p484@engsa/gems/jump_scripts-1.6.6/lib/jump_scripts/car_session.rb:67:in `keep_alive'
So one thing that I have noticed about my use case is that in the progress block, I also have some conditions where I SSH in and send some more commands. Obviously this is a wild guess but I could be in a situation where as I'm downloading something through a channel, I hit a timing issue where I try to create another channel and for some reason it has issues, since I'm pretty sure I'm using the same session.
I can try adding a mutex in both my code block, or alternatively in the open_channel method in session.rb of Net::SSH and see if that helps. I'm worried that a mutex might stop one of the channels from operating though, and lock it out.
Well I mutex'd the hell out of session.rb and that caused a deadlock. I think some smart mutex'ing might work here but it'll take me some more time to figure out where to do it.
Ok, I was able to solve this problem in my own code. The main problem was that from within a session open_channel exec block, I was calling a method that was doing another session exec (therefore open_channel) block. This was causing some sort of havoc inside session.rb where from within a channels iterator, (probably inside process or preprocess), we were calling exec which was attempting to modify channels (probably in open_channel).
I think this could be solved with some smart Mutexing inside session.rb but I didn't want to get involved there. I was able to modify my code to simply create a new session and therefore I was not messing with the session channels while iterating through them.
I guess I would need to file this as an issue with the SSH gem, not SCP. So I will close the issue here.
I have a case where Net::SCP is reproducibly failing on files that are larger that 10mb. I have verified that using a command line SCP on a *nix box doesn't fail for the same file.
Here you can see regular scp on the same file works: