Problem with remote_file downloading?

Chef Infra (archive)
1

See this gist: https://gist.github.com/d60768a9a4a9044bb7f8

Snippet here:

[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 96% done (653048 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 97% done (663184 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 99% done (673320 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 100% done (678469 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: remote_file[/opt/rvm/src/rvm-1.0.5.tar.gz]: Checking for file existence of /opt/rvm/src/rvm-1.0.5.tar.gz
[Wed, 08 Sep 2010 02:22:30 +0100] INFO: remote_file[/opt/rvm/src/rvm-1.0.5.tar.gz]: Creating /opt/rvm/src/rvm-1.0.5.tar.gz
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: copying remote file from origin /tmp/chef-rest20100908-31334-17ozxck-0 to destination /opt/rvm/src/rvm-1.0.5.tar.gz
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: rescued error in http connect, re-raising as Errno::ECONNREFUSED to hide bug in net/http
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: NoMethodError: undefined method closed?' for nil:NilClass [Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /usr/lib/ruby/1.8/net/http.rb:1060:inrequest’

In summary, it gives me progress report, then tells me it fails and tries again.

Any ideas?

-ash

2

could it be that the remote host is terminating the connection due to a
timeout? My guess here would be that the web server hosting up the
content/file has a default timeout set and that's causing your issue? is
that a possibility here?

--sahil

On Tue, Sep 7, 2010 at 6:24 PM, Ash Berlin ash_opscode@firemirror.comwrote:

See this gist: https://gist.github.com/d60768a9a4a9044bb7f8

Snippet here:

[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 96%
done (653048 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 97%
done (663184 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 99%
done (673320 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 100%
done (678469 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG:
remote_file[/opt/rvm/src/rvm-1.0.5.tar.gz]: Checking for file existence of
/opt/rvm/src/rvm-1.0.5.tar.gz
[Wed, 08 Sep 2010 02:22:30 +0100] INFO:
remote_file[/opt/rvm/src/rvm-1.0.5.tar.gz]: Creating
/opt/rvm/src/rvm-1.0.5.tar.gz
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: copying remote file from origin
/tmp/chef-rest20100908-31334-17ozxck-0 to destination
/opt/rvm/src/rvm-1.0.5.tar.gz
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: rescued error in http connect,
re-raising as Errno::ECONNREFUSED to hide bug in net/http
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: NoMethodError: undefined method
closed?' for nil:NilClass [Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /usr/lib/ruby/1.8/net/http.rb:1060:in request'

In summary, it gives me progress report, then tells me it fails and tries
again.

Any ideas?

-ash

3

On Tue, Sep 7, 2010 at 6:24 PM, Ash Berlin ash_opscode@firemirror.com wrote:

See this gist: https://gist.github.com/d60768a9a4a9044bb7f8

Snippet here:

[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 96% done (653048 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 97% done (663184 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 99% done (673320 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 100% done (678469 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: remote_file[/opt/rvm/src/rvm-1.0.5.tar.gz]: Checking for file existence of /opt/rvm/src/rvm-1.0.5.tar.gz
[Wed, 08 Sep 2010 02:22:30 +0100] INFO: remote_file[/opt/rvm/src/rvm-1.0.5.tar.gz]: Creating /opt/rvm/src/rvm-1.0.5.tar.gz
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: copying remote file from origin /tmp/chef-rest20100908-31334-17ozxck-0 to destination /opt/rvm/src/rvm-1.0.5.tar.gz
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: rescued error in http connect, re-raising as Errno::ECONNREFUSED to hide bug in net/http
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: NoMethodError: undefined method closed?' for nil:NilClass [Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /usr/lib/ruby/1.8/net/http.rb:1060:in request'

Is this consistently reproducible? And what version and patchlevel of
ruby are you using?

As you can see in the debug output, the net/http library that comes
with ruby has a bug in many commonly used versions where it sets some
variable to nil, and then calls #closed? on it, which raises a
NoMethodError. You usually see this when the connection is refused by
the server, so Chef papers over the bug to raise the "right" error.

In this case, it seems like the same bug in net/http is being
triggered by a condition other than connection refused.

In any case, I cannot reproduce this error in shef, though I am using
ruby 1.9.2 here.

chef:recipe > remote_file("/tmp/rvm.tgz") do
chef:recipe >
source("http://rvm.beginrescueend.com/releases/rvm-1.0.5.tar.gz")
chef:recipe ?> end
=> remote_file[/tmp/rvm.tgz]
chef:recipe > run_chef
[Tue, 07 Sep 2010 18:57:46 -0700] DEBUG: Processing
remote_file[/tmp/rvm.tgz] on fermi.local
[Tue, 07 Sep 2010 18:57:46 -0700] DEBUG: Checking
remote_file[/tmp/rvm.tgz] for changes
[Tue, 07 Sep 2010 18:57:46 -0700] DEBUG: Sending HTTP Request via GET
to rvm.beginrescueend.com:80/releases/rvm-1.0.5.tar.gz
[Tue, 07 Sep 2010 18:57:47 -0700] DEBUG: Streaming download from
http://rvm.beginrescueend.com/releases/rvm-1.0.5.tar.gz to tempfile
/var/folders/Ui/UiODstTvGJm3edk+EIMyf++++TI/-Tmp-/chef-rest20100907-27747-vm70is
[Tue, 07 Sep 2010 18:57:48 -0700] DEBUG: remote_file[/tmp/rvm.tgz]:
Checking for file existence of /tmp/rvm.tgz
[Tue, 07 Sep 2010 18:57:48 -0700] INFO: remote_file[/tmp/rvm.tgz]:
Creating /tmp/rvm.tgz
[Tue, 07 Sep 2010 18:57:48 -0700] DEBUG: copying remote file from
origin /var/folders/Ui/UiODstTvGJm3edk+EIMyf++++TI/-Tmp-/chef-rest20100907-27747-vm70is
to destination /tmp/rvm.tgz
=> true

Dan DeLeo

In summary, it gives me progress report, then tells me it fails and tries again.

Any ideas?

-ash

4

Can you wget or curl the file?

On Sep 7, 2010, at 6:24 PM, Ash Berlin ash_opscode@firemirror.com wrote:

See this gist: https://gist.github.com/d60768a9a4a9044bb7f8

Snippet here:

[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 96% done (653048 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 97% done (663184 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 99% done (673320 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /releases/rvm-1.0.5.tar.gz 100% done (678469 of 678469)
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: remote_file[/opt/rvm/src/rvm-1.0.5.tar.gz]: Checking for file existence of /opt/rvm/src/rvm-1.0.5.tar.gz
[Wed, 08 Sep 2010 02:22:30 +0100] INFO: remote_file[/opt/rvm/src/rvm-1.0.5.tar.gz]: Creating /opt/rvm/src/rvm-1.0.5.tar.gz
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: copying remote file from origin /tmp/chef-rest20100908-31334-17ozxck-0 to destination /opt/rvm/src/rvm-1.0.5.tar.gz
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: rescued error in http connect, re-raising as Errno::ECONNREFUSED to hide bug in net/http
[Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: NoMethodError: undefined method closed?' for nil:NilClass [Wed, 08 Sep 2010 02:22:30 +0100] DEBUG: /usr/lib/ruby/1.8/net/http.rb:1060:in request'

In summary, it gives me progress report, then tells me it fails and tries again.

Any ideas?

-ash

5

n 8 Sep 2010, at 03:38, Joshua Miller wrote:

Can you wget or curl the file?

curl -O works fine.

Its using ubuntu's system ruby, specifically 1.8.7.249-2

ruby 1.8.7 (2010-01-10 patchlevel 249) [x86_64-linux]

And I'm using the apt packages for chef - 0.9.8+dfsg

And yes this is reproduceable ever time on my server right now. The remote_file block is:

remote_file "#{rvm_path}/src/rvm-#{ver}.tar.gz" do
owner "rvm"
group "rvm"
mode 0644
source "http://rvm.beginrescueend.com/releases/rvm-#{ver}.tar.gz"

not_if do
begin
require "#{rvm_path}/lib/rvm/version.rb"
RVM::Version::STRING == ver
rescue Exception
false
end
end
end

ver in this case is "1.0.5"

Okay. I manually fixed the bug in net/http. The problem is the destination directory doesn't exist. Given that chef papers over any exception that happens in the processing block one step of the chef functions needs to rescue the exception and handle it more gracefully.

/usr/lib/ruby/1.8/fileutils.rb:1263:in initialize': No such file or directory - /opt/rvm/src/rvm-1.0.5.tar.gz (Errno::ENOENT) from /usr/lib/ruby/1.8/fileutils.rb:1263:in open'
from /usr/lib/ruby/1.8/fileutils.rb:1263:in copy_file' from /usr/lib/ruby/1.8/fileutils.rb:1262:in open'
from /usr/lib/ruby/1.8/fileutils.rb:1262:in copy_file' from /usr/lib/ruby/1.8/fileutils.rb:463:in copy_file'
from /usr/lib/ruby/1.8/fileutils.rb:383:in cp' from /usr/lib/ruby/1.8/fileutils.rb:1396:in fu_each_src_dest'
from /usr/lib/ruby/1.8/fileutils.rb:1412:in fu_each_src_dest0' from /usr/lib/ruby/1.8/fileutils.rb:1394:in fu_each_src_dest'
from /usr/lib/ruby/1.8/fileutils.rb:382:in cp' from /usr/lib/ruby/1.8/chef/provider/remote_file.rb:49:in action_create'
from /usr/lib/ruby/1.8/chef/rest.rb:135:in fetch' from /usr/lib/ruby/1.8/chef/rest.rb:249:in streaming_request'
from /usr/lib/ruby/1.8/chef/rest/rest_request.rb:62:in call' from /usr/lib/ruby/1.8/net/http.rb:1053:in request'
from /usr/lib/ruby/1.8/net/http.rb:2140:in reading_body' from /usr/lib/ruby/1.8/net/http.rb:1052:in request'
from /usr/lib/ruby/1.8/net/http.rb:1037:in request' from /usr/lib/ruby/1.8/net/http.rb:543:in start'
from /usr/lib/ruby/1.8/net/http.rb:1035:in request' from /usr/lib/ruby/1.8/chef/rest/rest_request.rb:60:in call'
from /usr/lib/ruby/1.8/chef/rest/rest_request.rb:75:in hide_net_http_bug' from /usr/lib/ruby/1.8/chef/rest/rest_request.rb:59:in call'
from /usr/lib/ruby/1.8/chef/rest.rb:245:in streaming_request' from /usr/lib/ruby/1.8/chef/rest.rb:280:in retriable_rest_request'
from /usr/lib/ruby/1.8/chef/rest.rb:243:in streaming_request' from /usr/lib/ruby/1.8/chef/rest.rb:135:in fetch'
from /usr/lib/ruby/1.8/chef/provider/remote_file.rb:43:in `action_create'

6

On 08.09.2010, at 11:40, Ash Berlin wrote:

n 8 Sep 2010, at 03:38, Joshua Miller wrote:

Can you wget or curl the file?

curl -O works fine.

Its using ubuntu's system ruby, specifically 1.8.7.249-2

ruby 1.8.7 (2010-01-10 patchlevel 249) [x86_64-linux]

And I'm using the apt packages for chef - 0.9.8+dfsg

And yes this is reproduceable ever time on my server right now. The remote_file block is:

remote_file "#{rvm_path}/src/rvm-#{ver}.tar.gz" do
owner "rvm"
group "rvm"
mode 0644
source "http://rvm.beginrescueend.com/releases/rvm-#{ver}.tar.gz"

not_if do
begin
require "#{rvm_path}/lib/rvm/version.rb"
RVM::Version::STRING == ver
rescue Exception
false
end
end
end

ver in this case is "1.0.5"

Okay. I manually fixed the bug in net/http. The problem is the destination directory doesn't exist. Given that chef papers over any exception that happens in the processing block one step of the chef functions needs to rescue the exception and handle it more gracefully.

and what happens if you create the directory before remote_file ? I don't think this can be considered a bug? or should it? another option would be add a

recursive option to the File or RemoteFile Ressource. But that would be not verbose methinks

cu edi

--
DI Edmund Haselwanter, edmund@haselwanter.com, http://edmund.haselwanter.com/
http://www.iteh.at | Facebook | http://at.linkedin.com/in/haselwanteredmund

7

On 8 Sep 2010, at 11:45, Haselwanter Edmund wrote:

On 08.09.2010, at 11:40, Ash Berlin wrote:

n 8 Sep 2010, at 03:38, Joshua Miller wrote:

Can you wget or curl the file?

curl -O works fine.

Its using ubuntu's system ruby, specifically 1.8.7.249-2

ruby 1.8.7 (2010-01-10 patchlevel 249) [x86_64-linux]

And I'm using the apt packages for chef - 0.9.8+dfsg

And yes this is reproduceable ever time on my server right now. The remote_file block is:

remote_file "#{rvm_path}/src/rvm-#{ver}.tar.gz" do
owner "rvm"
group "rvm"
mode 0644
source "http://rvm.beginrescueend.com/releases/rvm-#{ver}.tar.gz"

not_if do
begin
require "#{rvm_path}/lib/rvm/version.rb"
RVM::Version::STRING == ver
rescue Exception
false
end
end
end

ver in this case is "1.0.5"

Okay. I manually fixed the bug in net/http. The problem is the destination directory doesn't exist. Given that chef papers over any exception that happens in the processing block one step of the chef functions needs to rescue the exception and handle it more gracefully.

and what happens if you create the directory before remote_file ? I don't think this can be considered a bug? or should it? another option would be add a

recursive option to the File or RemoteFile Ressource. But that would be not verbose methinks

cu edi

If i create the directory it works. The bug here is that in attempting to work around one problem in net/http chef has hidden any number of other possible problems.

8

If i create the directory it works. The bug here is that in attempting to
work around one problem in net/http chef has hidden any number of other
possible problems.

Chef only rescues NoMethodError and only re-raises it as
Errno::ECONNREFUSED if the error message matches "undefined method
`closed?' for nil:NilClass"

You can see in the original gist that this is actually the error that
was raised, since the original error is logged to debug. The
backtrace there also shows that this error was raised from net/http.rb
line 1060, which is consistent with the net/http bug chef is papering
over.

So I'm still quite confused how remote file to a directory that
doesn't exist could cause this.

Dan DeLeo

9

On 8 Sep 2010, at 16:32, Daniel DeLeo wrote:

If i create the directory it works. The bug here is that in attempting to
work around one problem in net/http chef has hidden any number of other
possible problems.

Chef only rescues NoMethodError and only re-raises it as
Errno::ECONNREFUSED if the error message matches "undefined method
`closed?' for nil:NilClass"

chef/chef/lib/chef/rest/rest_request.rb at 1306d20e7f8fd64b069dbcf213f6230df4c67fae · chef/chef · GitHub

You can see in the original gist that this is actually the error that
was raised, since the original error is logged to debug. The
backtrace there also shows that this error was raised from net/http.rb
line 1060, which is consistent with the net/http bug chef is papering
over.

So I'm still quite confused how remote file to a directory that
doesn't exist could cause this.

Dan DeLeo

Because net/http did raise a NoMethodError due to @socket being already nil. But this was not caused by connection refused - the download succeeded and the block ran, and the block then excepted (at some point in that flow I guess @socket got closed and nulled).

-ash