Semi-random closed stream (IOError) on SFTP upload

Question

Semi-random closed stream (IOError) on SFTP upload

Closed this issue 9 years ago · 2 comments

Hello, I've been using dandelion for about a year now from a Mac and suddenly it's started throwing errors on some files during upload. I'm using SFTP.

I tried two tests:

Running the deployment with the latest commit (the commit has 6 files); it fails on the second file but the first file uploads just fine
I removed the ".revision" file and ran a deploy to trigger a full reupload. It uploaded quite a few files but then stopped with the same error on a seemingly random file.

In both cases, the file it fails on is the same within each test but not the same file for both tests. From what I can tell, it is not a permission issue; I can upload the file just fine using SFTP manually from the command line.

Here is what I get when I do a dry run, listing all the files that should be uploaded (note I replaced the path with (redacted) for confidentiality):

$ dandelion --config=production.yml deploy --dry-run
Connecting to (redacted)
Remote revision: a604a458f3a4506afc574dc45ee3d6f11a3b21b2
Deploying revision: b24d7d3f2e0baabd0382a502fdd9c5c8392c4c61
Deploying changes...
Writing file: config/general.config.php
Writing file: controllers/my-question.php
Writing file: controllers/thank-you.php
Writing file: lib/mail.php
Writing file: views/mail-templates/message.html.php
Writing file: views/my-question.html.php

Here is what I get when I do a real deploy (dropping --dry-run):
$ dandelion --config=production.yml deploy
Connecting to (redacted)
Remote revision: a604a458f3a4506afc574dc45ee3d6f11a3b21b2
Deploying revision: b24d7d3f2e0baabd0382a502fdd9c5c8392c4c61
Deploying changes...
Writing file: config/general.config.php
/Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/ruby_compat.rb:30:in select': closed stream (IOError) from /Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/ruby_compat.rb:30:inio_select'
from /Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/transport/packet_stream.rb:75:in available_for_read?' from /Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/transport/packet_stream.rb:87:innext_packet'
from /Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/transport/session.rb:183:in block in poll_message' from /Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/transport/session.rb:178:inloop'
from /Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/transport/session.rb:178:in poll_message' from /Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/connection/session.rb:461:indispatch_incoming_packets'
from /Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/connection/session.rb:222:in preprocess' from /Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/connection/session.rb:206:inprocess'
from /Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/connection/session.rb:170:in block in loop' from /Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/connection/session.rb:170:inloop'
from /Library/Ruby/Gems/2.0.0/gems/net-ssh-2.9.2/lib/net/ssh/connection/session.rb:170:in loop' from /Library/Ruby/Gems/2.0.0/gems/net-sftp-2.1.2/lib/net/sftp/session.rb:802:inloop'
from /Library/Ruby/Gems/2.0.0/gems/net-sftp-2.1.2/lib/net/sftp/operations/upload.rb:203:in wait' from /Library/Ruby/Gems/2.0.0/gems/net-sftp-2.1.2/lib/net/sftp/session.rb:103:inupload!'
from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/adapter/sftp.rb:35:in block in write' from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/utils.rb:9:intemp'
from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/adapter/sftp.rb:33:in write' from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/deployer.rb:49:indeploy_change!'
from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/deployer.rb:13:in block in deploy_changeset!' from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/changeset.rb:28:inblock in each'
from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/diff.rb:41:in block in each' from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/diff.rb:37:ineach'
from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/diff.rb:37:in each' from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/changeset.rb:20:ineach'
from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/deployer.rb:9:in deploy_changeset!' from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/command/deploy.rb:55:indeploy_changeset!'
from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/command/deploy.rb:30:in execute!' from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/lib/dandelion/cli.rb:73:inexecute!'
from /Library/Ruby/Gems/2.0.0/gems/dandelion-0.4.16/bin/dandelion:8:in <top (required)>' from /usr/bin/dandelion:23:inload'
from /usr/bin/dandelion:23:in `

'

It uploads the one file (config/general.config.php) and then fails. I can verify the changes for the one file are successfully uploaded at that point.

I asked my hosting provider (Rackspace) to see if anything has changed on their end, and they say nothing's changed in that regard. Do you have anything I could try? I'm out of ideas and would like to avoid having to use Cyberduck for deploys. :)

Answer 1 · 2015-12-16T04:01:41.000Z

Some additional info that may be helpful. I added a custom handler to the dandelion-0.4.16/lib/dandelion/adapter/sftp.rb file as follows:

  class CustomHandler
    def on_open(uploader, file)
      puts "starting upload: #{file.local} -> #{file.remote} (#{file.size} bytes)"
    end

    def on_put(uploader, file, offset, data)
      puts "writing #{data.length} bytes to #{file.remote} starting at #{offset}"
    end

    def on_close(uploader, file)
      puts "finished with #{file.remote}"
    end

    def on_mkdir(uploader, path)
      puts "creating directory #{path}"
    end

    def on_finish(uploader)
      puts "all done!"
    end
  end

Then, I added it to the write method (the :progress argument below) and added a new rescue on IOError:

      def write(file, data)
        temp(file, data) do |temp|
          begin
            @sftp.upload!(temp, path(file), :progress => CustomHandler.new) // I modified this line
          rescue Net::SFTP::StatusException => e
            raise unless e.code == 2
            mkdir_p(File.dirname(path(file)))
            @sftp.upload!(temp, path(file))
          rescue IOError => e  // I added this exception handling
            puts 'IOError!', e.inspect  // and this error message
          end
        end

This produced the following output:

Connecting to sftp://(redacted)/web/content/
Remote revision:    a604a458f3a4506afc574dc45ee3d6f11a3b21b2
Deploying revision: 05b81f751b0a83c551cdc86557974acd29ab8ba2
Deploying changes...
Writing file:  config/general.config.php
starting upload: /var/folders/44/ds7k7sdx7f56x308qkcsmkqr0000gn/T/config.general.config.php20151215-3350-1p97xwm -> /web/content/config/general.config.php (3965 bytes)
writing 3965 bytes to /web/content/config/general.config.php starting at 0
finished with /web/content/config/general.config.php
IOError!
#<IOError: closed stream>

The SFTP server logs look ok:

[15/Dec/2015:00:11:11 -0600] user 21442 sftp 0 OPEN /mnt/stor1-wc1-dfw1/368140/web/content/config/general.config.php - -
[15/Dec/2015:00:11:11 -0600] user 21442 sftp 3943 WRITE /mnt/stor1-wc1-dfw1/368140/web/content/config/general.config.php 0 OK

I'm guessing that the server is closing the connection somehow, but I've no idea on why. I installed wireshark (https://www.wireshark.org/) which tells me the server is sending a TCP FIN packet to indicate the termination of a session (https://ask.wireshark.org/questions/37630/wireshark-syn-ack-fin-get):

2402 246.713039 192.168.1.217 98.129.229.120 TCP 66 53756 → 22 [FIN, ACK] Seq=9850 Ack=5087 Win=131072 Len=0 TSval=281006002 TSecr=1865580184

However, I can use Cyberduck or the sftp command line client and upload all the files I want without closure. So, the problem appears to be isolated to when I use dandelion. Do you have any ideas on debugging further? I'm at a loss why dandelion would be failing here while I can upload the same file just fine to the SFTP server without problems.

Answer 2 · 2015-12-16T05:03:24.000Z

Ok, I figured out what was causing it, but have no clue why. Turns out it was just one file. I changed some text and HTML email message in a config file, simply deleting a line of text inside of a quoted string, and the upload started working again. If you want details, I can send them to you outside of this ticket.

I am not sure what the deal is but I've refactored my code to put the message elsewhere and it appears to be uploading fine now. Sorry for the hassle. I'll close the issue.