Truncated request bodies

Truncated request bodies

[Vadim Spivak]

There seems to be a ruby bug in 1.8.7 on OS X that's causing request
bodies to be truncated in unicorn when they're bigger than the
MAX_BODY (backed by a temp file instead of stringio).

Example of truncation: http://gist.github.com/211431

Smaller ruby bug example: http://gist.github.com/216703

I couldn't reproduce this on 1.9.1 on OS X or 1.8.7 on Linux.

Thanks,
Vadim

Re: Truncated request bodies

[Eric Wong]

Vadim Spivak <vadim@spivak.net> wrote:
> There seems to be a ruby bug in 1.8.7 on OS X that's causing request
> bodies to be truncated in unicorn when they're bigger than the
> MAX_BODY (backed by a temp file instead of stringio).
> 
> Example of truncation: http://gist.github.com/211431
> 
> Smaller ruby bug example: http://gist.github.com/216703

Hi Vadim,

What's the output of that standalone ruby example for you?  Is there a
bug filed with ruby-core I could look at?

Also, does using f << or f.syswrite change things?
f.sync = true should really make it unnecessary...

       f = File.open("bar", File::RDWR|File::CREAT, 0600)
       f.sync=true
       f.read  # why is this here?
       f << "Hello"  # or f.syswrite

       # would an explicit f.flush here work? shouldn't be needed
       # with f.sync = true
       puts "Should be 5: #{f.pos}"
       f.close

> I couldn't reproduce this on 1.9.1 on OS X or 1.8.7 on Linux.

I'll definitely need help with testing this then since I only have
Linux.

Which 1.8.7 patchlevel is your OS X Ruby at?  Do you know if the
OS X packagers apply any vendor patches on top of the stock Ruby distro
that could be causing it?  Are those patches downloadable anywhere?
Thanks!

-- 
Eric Wong

Re: Truncated request bodies

[Vadim Spivak]

> Hi Vadim,
>
> What's the output of that standalone ruby example for you?  Is there a
> bug filed with ruby-core I could look at?

"Should be 5: 0"

I haven't had a chance to file a bug yet and couldn't find

Also, if you don't set sync to true, then you get the expected output
5 instead of 0.

>
> Also, does using f << or f.syswrite change things?
> f.sync = true should really make it unnecessary...

I tried both and they didn't make a difference

>
>        f = File.open("bar", File::RDWR|File::CREAT, 0600)
>        f.sync=true
>        f.read  # why is this here?
>        f << "Hello"  # or f.syswrite
>
>        # would an explicit f.flush here work? shouldn't be needed
>        # with f.sync = true
>        puts "Should be 5: #{f.pos}"
>        f.close
>
> > I couldn't reproduce this on 1.9.1 on OS X or 1.8.7 on Linux.
>
> I'll definitely need help with testing this then since I only have
> Linux.
>
> Which 1.8.7 patchlevel is your OS X Ruby at?  Do you know if the
> OS X packagers apply any vendor patches on top of the stock Ruby distro
> that could be causing it?  Are those patches downloadable anywhere?
> Thanks!

I've tested both on 1.8.7 patch level 72.  Also, just to make sure it
wasn't a vendor patch, I just downloaded and compiled the source for
1.8.7 p72 and saw the same issue.

# ships with OS X
ruby 1.8.7 (2008-08-11 patchlevel 72) [universal-darwin10.0]

# compiled from source on OS X
ruby 1.8.7 (2008-08-11 patchlevel 72) [i686-darwin10.0.0]

# linux install
ruby 1.8.7 (2008-08-11 patchlevel 72) [x86_64-linux]

Also, I just tried it on a FreeBSD 7.2 VM and saw the same results as
on OS X.  (VM downloaded from http://www.thoughtpolice.co.uk/vmware/)

Thanks,
Vadim

>
> --
> Eric Wong

Re: Truncated request bodies

[Eric Wong]

Vadim Spivak <vadim@spivak.net> wrote:
> > Hi Vadim,
> >
> > What's the output of that standalone ruby example for you?  Is there a
> > bug filed with ruby-core I could look at?
> 
> "Should be 5: 0"
> 
> I haven't had a chance to file a bug yet and couldn't find
> 
> Also, if you don't set sync to true, then you get the expected output
> 5 instead of 0.

Interesting....

I bet it doesn't fail if you skip the f.read in there.

> > Also, does using f << or f.syswrite change things?
> > f.sync = true should really make it unnecessary...
> 
> I tried both and they didn't make a difference

sysread (instead of read) + syswrite() would've made a difference,
I very much hope, at least.

> >        f = File.open("bar", File::RDWR|File::CREAT, 0600)

                                ^-- btw, I would put File::TRUNC
				    there just in case because I
				    got 10 the 2nd time running it :x

> >        f.sync=true
> >        f.read  # why is this here?
> >        f << "Hello"  # or f.syswrite
> >
> >        # would an explicit f.flush here work? shouldn't be needed
> >        # with f.sync = true
> >        puts "Should be 5: #{f.pos}"
> >        f.close
> >
> > > I couldn't reproduce this on 1.9.1 on OS X or 1.8.7 on Linux.

This could be a stdio bug...  1.9.1 uses only the saner unistd.h
functions so it's immune to stdio bugs, but 1.8.7 uses stdio with
explicit fflush() when sync=true instead of calling
setvbuf(..._IONBF...) to disable buffering like a normal app would.

Looking at io.c in 1.8.7-p72, it even seems to call
setvbuf(..._IOFBF...) for full buffering on FreeBSD regardless
of sync mode (!)

> > I'll definitely need help with testing this then since I only have
> > Linux.

Does the following patch fix things for you?

diff --git a/lib/unicorn/util.rb b/lib/unicorn/util.rb
index 6b35426..0f517e9 100644
--- a/lib/unicorn/util.rb
+++ b/lib/unicorn/util.rb
@@ -54,7 +54,6 @@ module Unicorn
         end
         File.unlink(fp.path)
         fp.binmode
-        fp.sync = true
         fp
       end
---

On the flip side, I'm once again tempted to use sysread/sysseek/syswrite
because I have a very intense and long-standing distrust of luserspace
IO buffering libraries.

-- 
Eric Wong

Re: Truncated request bodies

[Eric Wong]

Eric Wong <normalperson@yhbt.net> wrote:
> 
> Does the following patch fix things for you?
> 
> diff --git a/lib/unicorn/util.rb b/lib/unicorn/util.rb
> index 6b35426..0f517e9 100644
> --- a/lib/unicorn/util.rb
> +++ b/lib/unicorn/util.rb
> @@ -54,7 +54,6 @@ module Unicorn
>          end
>          File.unlink(fp.path)
>          fp.binmode
> -        fp.sync = true
>          fp
>        end
> ---

Actually, that may not work since I need to call IO#stat.size,
in TeeInput, and if I explicitly call IO#flush then bad things
still end up happening :/

-- 
Eric Wong

Re: Truncated request bodies

[Eric Wong]

Eric Wong <normalperson@yhbt.net> wrote:
> Eric Wong <normalperson@yhbt.net> wrote:
> > 
> > Does the following patch fix things for you?

Hi Vadim, I actually just got a better patch offlist that
looks more reasonable than mine:

diff --git a/lib/unicorn/tee_input.rb b/lib/unicorn/tee_input.rb
index 188e2ea..7e77cdf 100644
--- a/lib/unicorn/tee_input.rb
+++ b/lib/unicorn/tee_input.rb
@@ -131,6 +131,7 @@ module Unicorn
         begin
           if parser.filter_body(dst, socket.readpartial(length, buf)).nil?
             @tmp.write(dst)
+            @tmp.seek(0, IO::SEEK_END) # workaround FreeBSD/OSX + MRI 1.8.x bug
             return dst
           end
         rescue EOFError
---

Also pushed out to git://git.bogomips.org/unicorn

Upon further inspection of the Ruby 1.8.7 source, I'm surprised it
worked anywhere, glibc + Linux included :x

I've managed to open a ticket on the issue for ruby-core:
  http://redmine.ruby-lang.org/issues/show/2267

-- 
Eric Wong

Re: Truncated request bodies

[Vadim Spivak]

Thanks Eric, I verified that it's working now.

On Sun, Oct 25, 2009 at 2:31 PM, Eric Wong <normalperson@yhbt.net> wrote:
> Eric Wong <normalperson@yhbt.net> wrote:
>> Eric Wong <normalperson@yhbt.net> wrote:
>> >
>> > Does the following patch fix things for you?
>
> Hi Vadim, I actually just got a better patch offlist that
> looks more reasonable than mine:
>
> diff --git a/lib/unicorn/tee_input.rb b/lib/unicorn/tee_input.rb
> index 188e2ea..7e77cdf 100644
> --- a/lib/unicorn/tee_input.rb
> +++ b/lib/unicorn/tee_input.rb
> @@ -131,6 +131,7 @@ module Unicorn
>         begin
>           if parser.filter_body(dst, socket.readpartial(length, buf)).nil?
>             @tmp.write(dst)
> +            @tmp.seek(0, IO::SEEK_END) # workaround FreeBSD/OSX + MRI 1.8.x bug
>             return dst
>           end
>         rescue EOFError
> ---
>
> Also pushed out to git://git.bogomips.org/unicorn
>
> Upon further inspection of the Ruby 1.8.7 source, I'm surprised it
> worked anywhere, glibc + Linux included :x
>
> I've managed to open a ticket on the issue for ruby-core:
>  http://redmine.ruby-lang.org/issues/show/2267
>
> --
> Eric Wong
> _______________________________________________
> mongrel-unicorn mailing list
> mongrel-unicorn@rubyforge.org
> http://rubyforge.org/mailman/listinfo/mongrel-unicorn
>