Comments (8)
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.
This issue was fixed in v3.0.0 (commit 266e810)
from net-sftp.
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.
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.
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.
I am closing the ticket. My user had /bin/false as user shell. With a Bash etc.. it works just fine.
from net-sftp.
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.
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)
- Is there a way to delete a file/directory? HOT 1
- NET-SFTP File Closing Behaviour HOT 1
- Blocked behavior when server closes connection while downloading HOT 2
- Error response on file upload, but uploads the file anyway
- Typo "raeddir" instead of "readdir"
- can't write CSV directly onto sftp.file.open HOT 1
- certificate /CN=netssh/DC=solutious/DC=com not valid after 2021-04-26 HOT 1
- All links are broken on the documentation page http://net-ssh.github.io/ HOT 1
- Net::SSH::Exception padding error HOT 5
- How to set the network connection timeout option ? HOT 2
- Upgrading to ruby 3.1 leads to "verify_signature" error HOT 7
- does not take UTF-8 more byte character length into account when writing data to a file
- Add Ruby 3.0 to travis CI HOT 1
- Allow use of `net-ssh` v7.0.0 (for OpenSSL 3 compatibility)
- Release a new version HOT 8
- could not settle on kex algorithm - SFTP connection failed HOT 2
- Changelog doesn't include breaking changes for v4 HOT 6
- Support connecting over a port other than 22 HOT 1
- unable to download multiple files using recursive: true
- Longname causes hard crash if `mtime` attr isn't set.
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
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.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from net-sftp.