Code Monkey home page Code Monkey logo

Comments (8)

jisaacks avatar jisaacks commented on August 17, 2024 2

I am also seeing this issue. I have found a way to easily reproduce. Create an sftp user who's password has expired:

sudo chage -d 2014-11-01 my_sftp_user
sudo chage -M 7 my_sftp_user

This user now, as soon as logs in will be asked to update their password. Now connecting to this user via Net::SFTP will trigger the undefined method any? for nil:NilClass

from net-sftp.

hosamaly avatar hosamaly commented on August 17, 2024 1

This issue was fixed in v3.0.0 (commit 266e810)

from net-sftp.

epcim avatar epcim commented on August 17, 2024

You do not set @pending_requests = {} in initializer since you rather expect net-ssh or the external code will call do_version function prior any work with the session.

from net-sftp.

delano avatar delano commented on August 17, 2024

Can you pass the debug flag to net-ssh and send the output from that. Here's an example:

options = { :verbose=>:debug }
Net::SSH.start("host", "user",options) do 
    ...
end

from net-sftp.

epcim avatar epcim commented on August 17, 2024

Here is the log. Not much info.

I believe the fix should go to net-sftp. The inicializer method in session.rb should contain:

pending_requests ||= {}
root@backup:/etc/backup/models# backup perform --trigger filesystem --config-file /etc/backup/config.rb --log-path=/var/log
[2014/05/14 14:20:14][info] Performing Backup for 'Filesystem backups (filesystem)'!
[2014/05/14 14:20:14][info] [ backup 4.0.1 : ruby 2.1.2p95 (2014-05-08 revision 45877) [x86_64-linux] ]
[2014/05/14 14:20:14][warn] Cleaner::Error: Cleanup Warning
[2014/05/14 14:20:14][warn]   The temporary backup folder '/root/Backup/.tmp'
[2014/05/14 14:20:14][warn]   appears to contain the package files from the previous backup!
[2014/05/14 14:20:14][warn]   /root/Backup/.tmp/filesystem.tar
[2014/05/14 14:20:14][warn]   These files will now be removed.
[2014/05/14 14:20:14][warn]   
[2014/05/14 14:20:14][warn]   Please check the log for messages and/or your notifications
[2014/05/14 14:20:14][warn]   concerning this backup: 'Filesystem backups (filesystem)'
[2014/05/14 14:20:14][warn]   The temporary files which had to be removed should not have existed.
[2014/05/14 14:20:14][info] Creating Archive 'backup_lab_default'...
[2014/05/14 14:20:14][info] Running system utility 'tar'...
[2014/05/14 14:20:14][info] tar:STDOUT: tar (GNU tar) 1.26
[2014/05/14 14:20:14][info] tar:STDOUT: Copyright (C) 2011 Free Software Foundation, Inc.
[2014/05/14 14:20:14][info] tar:STDOUT: License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>.
[2014/05/14 14:20:14][info] tar:STDOUT: This is free software: you are free to change and redistribute it.
[2014/05/14 14:20:14][info] tar:STDOUT: There is NO WARRANTY, to the extent permitted by law.
[2014/05/14 14:20:14][info] tar:STDOUT: 
[2014/05/14 14:20:14][info] tar:STDOUT: Written by John Gilmore and Jay Fenlason.
[2014/05/14 14:20:14][info] Using Compressor::Gzip for compression.
[2014/05/14 14:20:14][info]   Command: '/bin/gzip'
[2014/05/14 14:20:14][info]   Ext: '.gz'
[2014/05/14 14:20:16][info] Archive 'backup_lab_default' Complete!
[2014/05/14 14:20:16][info] Packaging the backup files...
[2014/05/14 14:20:16][info] Splitter configured with a chunk size of 4000MB and suffix length of 3.
[2014/05/14 14:20:16][info] Packaging Complete!
[2014/05/14 14:20:16][info] Cleaning up the temporary files...
[2014/05/14 14:20:16][info] Storage::SFTP (daily) Started...
D, [2014-05-14T16:20:16.787695 #25000] DEBUG -- net.ssh.transport.session[3f9cdcc8a1f0]: establishing connection to backup.lab.com:22
D, [2014-05-14T16:20:16.793122 #25000] DEBUG -- net.ssh.transport.session[3f9cdcc8a1f0]: connection established
I, [2014-05-14T16:20:16.848802 #25000]  INFO -- net.ssh.transport.server_version[3f9cdcc8801c]: negotiating protocol version
D, [2014-05-14T16:20:16.849229 #25000] DEBUG -- net.ssh.transport.server_version[3f9cdcc8801c]: remote is `SSH-2.0-OpenSSH_5.9p1 Debian-5ubuntu1.1'
D, [2014-05-14T16:20:16.849352 #25000] DEBUG -- net.ssh.transport.server_version[3f9cdcc8801c]: local is `SSH-2.0-Ruby/Net::SSH_2.7.0 x86_64-linux'
D, [2014-05-14T16:20:16.859933 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: read 984 bytes
D, [2014-05-14T16:20:16.860174 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 0 type 20 len 980
I, [2014-05-14T16:20:16.860287 #25000]  INFO -- net.ssh.transport.algorithms[3f9cdcc82388]: got KEXINIT from server
I, [2014-05-14T16:20:16.860453 #25000]  INFO -- net.ssh.transport.algorithms[3f9cdcc82388]: sending KEXINIT
D, [2014-05-14T16:20:16.860757 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: queueing packet nr 0 type 20 len 1620
D, [2014-05-14T16:20:16.861026 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: sent 1624 bytes
I, [2014-05-14T16:20:16.861083 #25000]  INFO -- net.ssh.transport.algorithms[3f9cdcc82388]: negotiating algorithms
D, [2014-05-14T16:20:16.861221 #25000] DEBUG -- net.ssh.transport.algorithms[3f9cdcc82388]: negotiated:
* kex: diffie-hellman-group-exchange-sha1
* host_key: ssh-rsa
* encryption_server: aes128-cbc
* encryption_client: aes128-cbc
* hmac_client: hmac-sha1
* hmac_server: hmac-sha1
* compression_client: none
* compression_server: none
* language_client: 
* language_server: 
D, [2014-05-14T16:20:16.861342 #25000] DEBUG -- net.ssh.transport.algorithms[3f9cdcc82388]: exchanging keys
D, [2014-05-14T16:20:16.861604 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: queueing packet nr 1 type 34 len 20
D, [2014-05-14T16:20:16.863313 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: sent 24 bytes
D, [2014-05-14T16:20:16.863429 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: read 152 bytes
D, [2014-05-14T16:20:16.863517 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 1 type 31 len 148
D, [2014-05-14T16:20:16.865419 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: queueing packet nr 2 type 32 len 140
D, [2014-05-14T16:20:16.866216 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: sent 144 bytes
D, [2014-05-14T16:20:16.868672 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: read 720 bytes
D, [2014-05-14T16:20:16.868775 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 2 type 33 len 700
D, [2014-05-14T16:20:16.870607 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: queueing packet nr 3 type 21 len 20
D, [2014-05-14T16:20:16.870820 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: sent 24 bytes
D, [2014-05-14T16:20:16.870975 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 3 type 21 len 12
D, [2014-05-14T16:20:16.871450 #25000] DEBUG -- net.ssh.authentication.session[3f9cdd204cfc]: beginning authentication of `backup_upload'
D, [2014-05-14T16:20:16.871614 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: queueing packet nr 4 type 5 len 28
D, [2014-05-14T16:20:16.871733 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: sent 52 bytes
D, [2014-05-14T16:20:16.909862 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: read 52 bytes
D, [2014-05-14T16:20:16.910050 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 4 type 6 len 28
D, [2014-05-14T16:20:16.910219 #25000] DEBUG -- net.ssh.authentication.session[3f9cdd204cfc]: trying none
D, [2014-05-14T16:20:16.910332 #25000] DEBUG -- net.ssh.authentication.session[3f9cdd204cfc]: Mechanism none was requested, but isn't a known type.  Ignoring it.
D, [2014-05-14T16:20:16.910372 #25000] DEBUG -- net.ssh.authentication.session[3f9cdd204cfc]: trying publickey
D, [2014-05-14T16:20:16.910654 #25000] DEBUG -- net.ssh.authentication.agent[3f9cdd20051c]: connecting to ssh-agent
E, [2014-05-14T16:20:16.910749 #25000] ERROR -- net.ssh.authentication.agent[3f9cdd20051c]: could not connect to ssh-agent
D, [2014-05-14T16:20:16.910964 #25000] DEBUG -- net.ssh.authentication.methods.publickey[3f9cdd200af8]: trying publickey (7c:33:a3:f4:99:eb:61:64:d6:17:bb:4f:74:e7:2d:5b)
D, [2014-05-14T16:20:16.911120 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: queueing packet nr 5 type 50 len 364
D, [2014-05-14T16:20:16.914111 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: sent 388 bytes
D, [2014-05-14T16:20:16.914488 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: read 68 bytes
D, [2014-05-14T16:20:16.914802 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 5 type 51 len 44
D, [2014-05-14T16:20:16.915006 #25000] DEBUG -- net.ssh.authentication.session[3f9cdd204cfc]: allowed methods: publickey,password
D, [2014-05-14T16:20:16.915126 #25000] DEBUG -- net.ssh.authentication.session[3f9cdd204cfc]: trying password
D, [2014-05-14T16:20:16.915400 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: queueing packet nr 6 type 50 len 76
D, [2014-05-14T16:20:16.915566 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: sent 100 bytes
D, [2014-05-14T16:20:16.917245 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: read 36 bytes
D, [2014-05-14T16:20:16.917943 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 6 type 52 len 12
D, [2014-05-14T16:20:16.918077 #25000] DEBUG -- net.ssh.authentication.methods.password[3f9cdd1fb60c]: password succeeded
D, [2014-05-14T16:20:16.918571 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: queueing packet nr 7 type 90 len 44
D, [2014-05-14T16:20:16.919116 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: sent 68 bytes
D, [2014-05-14T16:20:17.105214 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: read 52 bytes
D, [2014-05-14T16:20:17.105493 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 7 type 91 len 28
I, [2014-05-14T16:20:17.105659 #25000]  INFO -- net.ssh.connection.session[3f9cdd1f8d80]: channel_open_confirmation: 0 0 0 32768
I, [2014-05-14T16:20:17.105817 #25000]  INFO -- net.ssh.connection.channel[3f9cdd1f8ab0]: sending channel request "env"
D, [2014-05-14T16:20:17.105950 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: queueing packet nr 8 type 98 len 44
D, [2014-05-14T16:20:17.106095 #25000] DEBUG -- net.sftp.session[3f9cdd1f8c40]: requesting sftp subsystem
I, [2014-05-14T16:20:17.106147 #25000]  INFO -- net.ssh.connection.channel[3f9cdd1f8ab0]: sending channel request "subsystem"
D, [2014-05-14T16:20:17.106236 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: queueing packet nr 9 type 98 len 44
D, [2014-05-14T16:20:17.106412 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: sent 136 bytes
D, [2014-05-14T16:20:17.160745 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: read 88 bytes
D, [2014-05-14T16:20:17.161155 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 8 type 93 len 28
I, [2014-05-14T16:20:17.161354 #25000]  INFO -- net.ssh.connection.session[3f9cdd1f8d80]: channel_window_adjust: 0 +2097152
D, [2014-05-14T16:20:17.161550 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 9 type 99 len 12
I, [2014-05-14T16:20:17.161775 #25000]  INFO -- net.ssh.connection.session[3f9cdd1f8d80]: channel_success: 0
D, [2014-05-14T16:20:17.161885 #25000] DEBUG -- net.sftp.session[3f9cdd1f8c40]: sftp subsystem successfully started
D, [2014-05-14T16:20:17.162241 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: queueing packet nr 10 type 94 len 28
D, [2014-05-14T16:20:17.162452 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: sent 52 bytes
D, [2014-05-14T16:20:17.164656 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: read 140 bytes
D, [2014-05-14T16:20:17.164943 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 10 type 98 len 44
I, [2014-05-14T16:20:17.165216 #25000]  INFO -- net.ssh.connection.session[3f9cdd1f8d80]: channel_request: 0 exit-status false
D, [2014-05-14T16:20:17.165482 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 11 type 96 len 12
I, [2014-05-14T16:20:17.165628 #25000]  INFO -- net.ssh.connection.session[3f9cdd1f8d80]: channel_eof: 0
D, [2014-05-14T16:20:17.165826 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: received packet nr 12 type 97 len 12
I, [2014-05-14T16:20:17.165962 #25000]  INFO -- net.ssh.connection.session[3f9cdd1f8d80]: channel_close: 0
D, [2014-05-14T16:20:17.166213 #25000] DEBUG -- tcpsocket[3f9cdcc89624]: queueing packet nr 11 type 97 len 28
D, [2014-05-14T16:20:17.166337 #25000] DEBUG -- net.sftp.session[3f9cdd1f8c40]: sftp channel closed
E, [2014-05-14T16:20:17.166546 #25000] ERROR -- net.ssh.transport.session[3f9cdcc8a1f0]: forcing connection closed
[2014/05/14 14:20:17][error] Model::Error: Backup for Filesystem backups (filesystem) Failed!
[2014/05/14 14:20:17][error] --- Wrapped Exception ---
[2014/05/14 14:20:17][error] NoMethodError: undefined method `any?' for nil:NilClass
[2014/05/14 14:20:17][error] 
[2014/05/14 14:20:17][error] Backtrace:
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-sftp-2.1.2/lib/net/sftp/session.rb:802:in `block in loop'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:220:in `preprocess'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:205:in `process'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:169:in `block in loop'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:169:in `loop'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:169:in `loop'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-sftp-2.1.2/lib/net/sftp/session.rb:803:in `loop'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-sftp-2.1.2/lib/net/sftp.rb:35:in `start'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/storage/sftp.rb:29:in `connection'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/storage/sftp.rb:35:in `transfer!'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/storage/base.rb:35:in `perform!'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/model.rb:269:in `each'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/model.rb:269:in `block in perform!'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/model.rb:268:in `each'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/model.rb:268:in `perform!'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/cli.rb:153:in `perform'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/thor-0.18.1/lib/thor/command.rb:27:in `run'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/thor-0.18.1/lib/thor/invocation.rb:120:in `invoke_command'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/thor-0.18.1/lib/thor.rb:363:in `dispatch'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/thor-0.18.1/lib/thor/base.rb:439:in `start'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/bin/backup:5:in `<top (required)>'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/bin/backup:23:in `load'
[2014/05/14 14:20:17][error]   /opt/rbenv/versions/2.1.2/bin/backup:23:in `<main>'
[2014/05/14 14:20:17][warn] Cleaner::Error: Cleanup Warning
[2014/05/14 14:20:17][warn]   The temporary backup folder '/root/Backup/.tmp'
[2014/05/14 14:20:17][warn]   appears to contain the backup files which were to be stored:
[2014/05/14 14:20:17][warn]   /root/Backup/.tmp/filesystem.tar
[2014/05/14 14:20:17][warn]   
[2014/05/14 14:20:17][warn]   Make sure you check these files before the next scheduled backup for
[2014/05/14 14:20:17][warn]   'Filesystem backups (filesystem)'
[2014/05/14 14:20:17][warn]   These files will be removed at that time!
[2014/05/14 14:20:17][info] CLI::Error: Backup will now continue...
[2014/05/14 14:20:17][info]   The following triggers will now be processed:
[2014/05/14 14:20:17][info]   (filesystem)
[2014/05/14 14:20:17][info] Performing Backup for 'Filesystem backups (filesystem)'!
[2014/05/14 14:20:17][info] [ backup 4.0.1 : ruby 2.1.2p95 (2014-05-08 revision 45877) [x86_64-linux] ]
[2014/05/14 14:20:17][warn] Cleaner::Error: Cleanup Warning
[2014/05/14 14:20:17][warn]   The temporary backup folder '/root/Backup/.tmp'
[2014/05/14 14:20:17][warn]   appears to contain the package files from the previous backup!
[2014/05/14 14:20:17][warn]   /root/Backup/.tmp/filesystem.tar
[2014/05/14 14:20:17][warn]   These files will now be removed.
[2014/05/14 14:20:17][warn]   
[2014/05/14 14:20:17][warn]   Please check the log for messages and/or your notifications
[2014/05/14 14:20:17][warn]   concerning this backup: 'Filesystem backups (filesystem)'
[2014/05/14 14:20:17][warn]   The temporary files which had to be removed should not have existed.
[2014/05/14 14:20:17][info] Creating Archive 'backub_lab_default'...
[2014/05/14 14:20:17][info] Using Compressor::Gzip for compression.
[2014/05/14 14:20:17][info]   Command: '/bin/gzip'
[2014/05/14 14:20:17][info]   Ext: '.gz'
[2014/05/14 14:20:19][info] Archive 'backup_lab_default' Complete!
[2014/05/14 14:20:19][info] Packaging the backup files...
[2014/05/14 14:20:19][info] Splitter configured with a chunk size of 4000MB and suffix length of 3.
[2014/05/14 14:20:19][info] Packaging Complete!
[2014/05/14 14:20:19][info] Cleaning up the temporary files...
[2014/05/14 14:20:19][info] Storage::SFTP (daily) Started...
D, [2014-05-14T16:20:19.540395 #25000] DEBUG -- net.ssh.transport.session[3f9cdd1d1e88]: establishing connection to backup.lab.com:22
D, [2014-05-14T16:20:19.547277 #25000] DEBUG -- net.ssh.transport.session[3f9cdd1d1e88]: connection established
I, [2014-05-14T16:20:19.548179 #25000]  INFO -- net.ssh.transport.server_version[3f9cdd1d1618]: negotiating protocol version
D, [2014-05-14T16:20:19.550499 #25000] DEBUG -- net.ssh.transport.server_version[3f9cdd1d1618]: remote is `SSH-2.0-OpenSSH_5.9p1 Debian-5ubuntu1.1'
D, [2014-05-14T16:20:19.550584 #25000] DEBUG -- net.ssh.transport.server_version[3f9cdd1d1618]: local is `SSH-2.0-Ruby/Net::SSH_2.7.0 x86_64-linux'
D, [2014-05-14T16:20:19.557984 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: read 984 bytes
D, [2014-05-14T16:20:19.558139 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 0 type 20 len 980
I, [2014-05-14T16:20:19.558760 #25000]  INFO -- net.ssh.transport.algorithms[3f9cdd1d022c]: got KEXINIT from server
I, [2014-05-14T16:20:19.559409 #25000]  INFO -- net.ssh.transport.algorithms[3f9cdd1d022c]: sending KEXINIT
D, [2014-05-14T16:20:19.560103 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: queueing packet nr 0 type 20 len 1620
D, [2014-05-14T16:20:19.560810 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: sent 1624 bytes
I, [2014-05-14T16:20:19.561871 #25000]  INFO -- net.ssh.transport.algorithms[3f9cdd1d022c]: negotiating algorithms
D, [2014-05-14T16:20:19.562629 #25000] DEBUG -- net.ssh.transport.algorithms[3f9cdd1d022c]: negotiated:
* kex: diffie-hellman-group-exchange-sha1
* host_key: ssh-rsa
* encryption_server: aes128-cbc
* encryption_client: aes128-cbc
* hmac_client: hmac-sha1
* hmac_server: hmac-sha1
* compression_client: none
* compression_server: none
* language_client: 
* language_server: 
D, [2014-05-14T16:20:19.564894 #25000] DEBUG -- net.ssh.transport.algorithms[3f9cdd1d022c]: exchanging keys
D, [2014-05-14T16:20:19.566175 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: queueing packet nr 1 type 34 len 20
D, [2014-05-14T16:20:19.568840 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: sent 24 bytes
D, [2014-05-14T16:20:19.569332 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: read 152 bytes
D, [2014-05-14T16:20:19.569888 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 1 type 31 len 148
D, [2014-05-14T16:20:19.572201 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: queueing packet nr 2 type 32 len 140
D, [2014-05-14T16:20:19.627338 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: sent 144 bytes
D, [2014-05-14T16:20:19.629612 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: read 720 bytes
D, [2014-05-14T16:20:19.629847 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 2 type 33 len 700
D, [2014-05-14T16:20:19.634617 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: queueing packet nr 3 type 21 len 20
D, [2014-05-14T16:20:19.635931 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: sent 24 bytes
D, [2014-05-14T16:20:19.637215 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 3 type 21 len 12
D, [2014-05-14T16:20:19.639123 #25000] DEBUG -- net.ssh.authentication.session[3f9cdd1661ec]: beginning authentication of `backup_upload'
D, [2014-05-14T16:20:19.640710 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: queueing packet nr 4 type 5 len 28
D, [2014-05-14T16:20:19.641524 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: sent 52 bytes
D, [2014-05-14T16:20:19.642088 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: read 52 bytes
D, [2014-05-14T16:20:19.642772 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 4 type 6 len 28
D, [2014-05-14T16:20:19.643371 #25000] DEBUG -- net.ssh.authentication.session[3f9cdd1661ec]: trying none
D, [2014-05-14T16:20:19.644003 #25000] DEBUG -- net.ssh.authentication.session[3f9cdd1661ec]: Mechanism none was requested, but isn't a known type.  Ignoring it.
D, [2014-05-14T16:20:19.644505 #25000] DEBUG -- net.ssh.authentication.session[3f9cdd1661ec]: trying publickey
D, [2014-05-14T16:20:19.645458 #25000] DEBUG -- net.ssh.authentication.agent[3f9cdd139548]: connecting to ssh-agent
E, [2014-05-14T16:20:19.645875 #25000] ERROR -- net.ssh.authentication.agent[3f9cdd139548]: could not connect to ssh-agent
D, [2014-05-14T16:20:19.646624 #25000] DEBUG -- net.ssh.authentication.methods.publickey[3f9cdd139dcc]: trying publickey (7c:33:a3:f4:99:eb:61:64:d6:17:bb:4f:74:e7:2d:5b)
D, [2014-05-14T16:20:19.647235 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: queueing packet nr 5 type 50 len 364
D, [2014-05-14T16:20:19.649676 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: sent 388 bytes
D, [2014-05-14T16:20:19.651010 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: read 68 bytes
D, [2014-05-14T16:20:19.651667 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 5 type 51 len 44
D, [2014-05-14T16:20:19.652260 #25000] DEBUG -- net.ssh.authentication.session[3f9cdd1661ec]: allowed methods: publickey,password
D, [2014-05-14T16:20:19.652959 #25000] DEBUG -- net.ssh.authentication.session[3f9cdd1661ec]: trying password
D, [2014-05-14T16:20:19.653464 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: queueing packet nr 6 type 50 len 76
D, [2014-05-14T16:20:19.657712 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: sent 100 bytes
D, [2014-05-14T16:20:19.658802 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: read 36 bytes
D, [2014-05-14T16:20:19.661504 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 6 type 52 len 12
D, [2014-05-14T16:20:19.662119 #25000] DEBUG -- net.ssh.authentication.methods.password[3f9cdd125444]: password succeeded
D, [2014-05-14T16:20:19.662699 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: queueing packet nr 7 type 90 len 44
D, [2014-05-14T16:20:19.663372 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: sent 68 bytes
D, [2014-05-14T16:20:19.875716 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: read 52 bytes
D, [2014-05-14T16:20:19.875993 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 7 type 91 len 28
I, [2014-05-14T16:20:19.876135 #25000]  INFO -- net.ssh.connection.session[3f9cdd1231f8]: channel_open_confirmation: 0 0 0 32768
I, [2014-05-14T16:20:19.876277 #25000]  INFO -- net.ssh.connection.channel[3f9cdd122f3c]: sending channel request "env"
D, [2014-05-14T16:20:19.876510 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: queueing packet nr 8 type 98 len 44
D, [2014-05-14T16:20:19.876738 #25000] DEBUG -- net.sftp.session[3f9cdd1230cc]: requesting sftp subsystem
I, [2014-05-14T16:20:19.876822 #25000]  INFO -- net.ssh.connection.channel[3f9cdd122f3c]: sending channel request "subsystem"
D, [2014-05-14T16:20:19.876948 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: queueing packet nr 9 type 98 len 44
D, [2014-05-14T16:20:19.877109 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: sent 136 bytes
D, [2014-05-14T16:20:19.878283 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: read 88 bytes
D, [2014-05-14T16:20:19.878868 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 8 type 93 len 28
I, [2014-05-14T16:20:19.879432 #25000]  INFO -- net.ssh.connection.session[3f9cdd1231f8]: channel_window_adjust: 0 +2097152
D, [2014-05-14T16:20:19.880064 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 9 type 99 len 12
I, [2014-05-14T16:20:19.932876 #25000]  INFO -- net.ssh.connection.session[3f9cdd1231f8]: channel_success: 0
D, [2014-05-14T16:20:19.933067 #25000] DEBUG -- net.sftp.session[3f9cdd1230cc]: sftp subsystem successfully started
D, [2014-05-14T16:20:19.933448 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: queueing packet nr 10 type 94 len 28
D, [2014-05-14T16:20:19.933686 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: sent 52 bytes
D, [2014-05-14T16:20:19.936031 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: read 140 bytes
D, [2014-05-14T16:20:19.936331 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 10 type 98 len 44
I, [2014-05-14T16:20:19.936607 #25000]  INFO -- net.ssh.connection.session[3f9cdd1231f8]: channel_request: 0 exit-status false
D, [2014-05-14T16:20:19.936859 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 11 type 96 len 12
I, [2014-05-14T16:20:19.937004 #25000]  INFO -- net.ssh.connection.session[3f9cdd1231f8]: channel_eof: 0
D, [2014-05-14T16:20:19.937248 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: received packet nr 12 type 97 len 12
I, [2014-05-14T16:20:19.937399 #25000]  INFO -- net.ssh.connection.session[3f9cdd1231f8]: channel_close: 0
D, [2014-05-14T16:20:19.937636 #25000] DEBUG -- tcpsocket[3f9cdd1d1b40]: queueing packet nr 11 type 97 len 28
D, [2014-05-14T16:20:19.937797 #25000] DEBUG -- net.sftp.session[3f9cdd1230cc]: sftp channel closed
E, [2014-05-14T16:20:19.937979 #25000] ERROR -- net.ssh.transport.session[3f9cdd1d1e88]: forcing connection closed
[2014/05/14 14:20:19][error] Model::Error: Backup for Filesystem backups (filesystem) Failed!
[2014/05/14 14:20:19][error] --- Wrapped Exception ---
[2014/05/14 14:20:19][error] NoMethodError: undefined method `any?' for nil:NilClass
[2014/05/14 14:20:19][error] 
[2014/05/14 14:20:19][error] Backtrace:
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-sftp-2.1.2/lib/net/sftp/session.rb:802:in `block in loop'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:220:in `preprocess'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:205:in `process'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:169:in `block in loop'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:169:in `loop'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-ssh-2.7.0/lib/net/ssh/connection/session.rb:169:in `loop'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-sftp-2.1.2/lib/net/sftp/session.rb:803:in `loop'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/net-sftp-2.1.2/lib/net/sftp.rb:35:in `start'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/storage/sftp.rb:29:in `connection'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/storage/sftp.rb:35:in `transfer!'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/storage/base.rb:35:in `perform!'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/model.rb:269:in `each'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/model.rb:269:in `block in perform!'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/model.rb:268:in `each'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/model.rb:268:in `perform!'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/lib/backup/cli.rb:153:in `perform'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/thor-0.18.1/lib/thor/command.rb:27:in `run'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/thor-0.18.1/lib/thor/invocation.rb:120:in `invoke_command'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/thor-0.18.1/lib/thor.rb:363:in `dispatch'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/thor-0.18.1/lib/thor/base.rb:439:in `start'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/lib/ruby/gems/2.1.0/gems/backup-4.0.1/bin/backup:5:in `<top (required)>'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/bin/backup:23:in `load'
[2014/05/14 14:20:19][error]   /opt/rbenv/versions/2.1.2/bin/backup:23:in `<main>'
[2014/05/14 14:20:19][warn] Cleaner::Error: Cleanup Warning
[2014/05/14 14:20:19][warn]   The temporary backup folder '/root/Backup/.tmp'
[2014/05/14 14:20:19][warn]   appears to contain the backup files which were to be stored:
[2014/05/14 14:20:19][warn]   /root/Backup/.tmp/filesystem.tar
[2014/05/14 14:20:19][warn]   
[2014/05/14 14:20:19][warn]   Make sure you check these files before the next scheduled backup for
[2014/05/14 14:20:19][warn]   'Filesystem backups (filesystem)'
[2014/05/14 14:20:19][warn]   These files will be removed at that time!
root@backup:/etc/backup/models# 

from net-sftp.

epcim avatar epcim commented on August 17, 2024

I am closing the ticket. My user had /bin/false as user shell. With a Bash etc.. it works just fine.

from net-sftp.

epcim avatar epcim commented on August 17, 2024

The newly reprovisioned VM had a same issue - without /bin/false as user shell. I suggest to add @pending_requests = {} to initializer method. Then the issue dissappear.

from net-sftp.

kmwhite avatar kmwhite commented on August 17, 2024

For whatever it's worth, I also ran into this issue when attempting to use the SFTP gem to transfer files off of an SSH server. Using a proper SFTP service fixed the issue.

from net-sftp.

Related Issues (20)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.