Forum: Ruby odd http header corruption

Announcement (2017-05-07): www.ruby-forum.com is now read-only since I unfortunately do not have the time to support and maintain the forum any more. Please see rubyonrails.org/community and ruby-lang.org/en/community for other Rails- und Ruby-related community platforms.
Cb33b32bd5d675db7be148542976e510?d=identicon&s=25 Sam Joseph (Guest)
on 2006-02-06 10:17
(Received via mailing list)
Hi there,

I can't tell if this is a problem with the ruby cgi library or with
rails action pack (no response from the rails list so far), but I get an
occasional error in the http headers from rails like this:

HTTP/1.x 200 OK
Date: Thu, 02 Feb 2006 20:56:03 GMT
Server: Apache/2.0.54 (Debian GNU/Linux) PHP/4.3.10-16 mod_ruby/1.2.4
Ruby/1.8.4(2005-12-24)
#<#<Class: 0x40b8e99c>:0x40b8e8d4>Content-Type: text/html
Cache-Control: no-cache

Some kind of object data is getting dumped in front of the Content-Type,
which screws up how some browsers display the page.

Setting Content-Type explicitly in the controller doesn't seem to help,
and so far I have been unable to detect what causes this, or why it
happens under some circumstances and not others - I am posting this here
in case anybody has seen something similar, or has ideas about possible
causes.

Many thanks

CHEERS> SAM
Cb33b32bd5d675db7be148542976e510?d=identicon&s=25 Sam Joseph (Guest)
on 2006-02-07 18:47
(Received via mailing list)
Hi,

So more information on the header corruption.

I tried adding a slice! instruction to remove the offending part of the
http headers. Rails ActionController::CgiResponse normally uses the
following:

output.write(@cgi.header(@headers))

which I replaced with:

headers = @cgi.header(@headers)
headers.slice!(/#<#<(C|c)lass: 0x[\w\d]*>:0x[\w\d]*>/)
output.write(headers)

testing that my regex really did match the offending string.

However, this addition did not remove the offending string, and writing
the headers out into the body of the response gave me this

Content-Type: text/html
Set-Cookie: _session_id=936ba003910da551a472708d4b7b3ff3; path=/
Status: 200 OK
Cache-Control: no-cache

<html>
<head>

suggesting to me that the problem was being introduced at a different
stage ... However, superficially I cannot work out how this set of
headers is actually transformed into the headers we see in the HTTP
header itself which looks like this:

HTTP/1.x 200 OK
Date: Tue, 07 Feb 2006 13:59:08 GMT
Server: Apache/2.0.54 (Debian GNU/Linux) PHP/4.3.10-16
#<#<Class: 0x40bdaff4>:0x40bdaf2c>Content-Type: text/html
Cache-Control: no-cache
Set-Cookie: _session_id=936ba003910da551a472708d4b7b3ff3; path=/
Keep-Alive: timeout=15, max=100
Connection: Keep-Alive
Transfer-Encoding: chunked
Content-Type: text/plain

The implication being that the header string is transformed somewhere
that I have been unable to determine.

I've even checked by dumping the @cgi, @headers and ENV objects as YAML
into the HTML body, and then reassembling them locally. As far as I can
tell, within rails, the operation:

@cgi.header(@headers)

generates a string like:

Content-Type: text/html
Set-Cookie: _session_id=936ba003910da551a472708d4b7b3ff3; path=/
Status: 200 OK
Cache-Control: no-cache

but the output from rails through Apache is a properly formed HTTP
header.

From looking at the ruby cgi library, I can see that if I was using
mod_ruby that the output would be different, and would be directed
straight to Apache, but I'm not using mod_ruby, so now I have two
problems:

1. I can't work out how the results of calling @cgi.header(@headers) in
rails actually gets turned into a real HTTP response
2. I still can't see where this strange string is being introduced

I have discovered a work around that is a bit of a hack, but I will post
the patch to the rails ticket I have opened:

http://dev.rubyonrails.org/ticket/3703

I'd still like to work out what causes this problem so I can properly be
rid of it.

Another very weird thing is that I appear to be able to comment out the
contents of the process_cgi method in actioncontrollers cgi_process.rb,
but that things still keep functioning - other changes in the same file
have effects on the http output, just not for the process_cgi method,
which is the only place I can see in the code where the CgiResponse out
method gets called. Clearly I'm still missing a big chunk of this
puzzle.

CHEERS> SAM
58479f76374a3ba3c69b9804163f39f4?d=identicon&s=25 Eric Hodel (Guest)
on 2006-02-07 22:27
(Received via mailing list)
On Feb 6, 2006, at 1:16 AM, Sam Joseph wrote:

> Ruby/1.8.4(2005-12-24)
> #<#<Class: 0x40b8e99c>:0x40b8e8d4>Content-Type: text/html
> Cache-Control: no-cache

You're adding a metaclass thingy to your headers.

> possible
> causes.

Does it go away if you take that out?

I'm going to blame your code or Rails on this one.

--
Eric Hodel - drbrain@segment7.net - http://segment7.net
This implementation is HODEL-HASH-9600 compliant

http://trackmap.robotcoop.com
12aae38b80286b5b3c2c51caac9f41b2?d=identicon&s=25 Zev Blut (Guest)
on 2006-02-08 05:20
(Received via mailing list)
Hello Sam,

On Wed, 08 Feb 2006 02:45:27 +0900, Sam Joseph <sam@neurogrid.com>
wrote:

> header itself which looks like this:
> Content-Type: text/plain
This looks like you have a "puts someobj.inspect" in your code.
Depending upon how you are running your system this rogue puts is
being called before the header output and is going directly to the
output stream.  This is why your attempt to cut it out does not work.

I would grep your code for an "inspect" and if that fails "puts".
Hopefully, that show you where the problem is.

Cheers,
Zev
Cb33b32bd5d675db7be148542976e510?d=identicon&s=25 Sam Joseph (Guest)
on 2006-02-08 15:18
(Received via mailing list)
Hi Zev,

Zev Blut wrote:

> This looks like you have a "puts someobj.inspect" in your code.
> Depending upon how you are running your system this rogue puts is
> being called before the header output and is going directly to the
> output stream.  This is why your attempt to cut it out does not work.

Indeed I have suspected as much.

> I would grep your code for an "inspect" and if that fails "puts".

I had already done so - I have no "puts" or "print" outside my test
classes, and no inspects outside of my logging code.  I've used the
eclipse search function to scan all the code, and find | xargs grep on
the server.  The only things that I can imagine being remotely
responsible are things like:

./app/models/message.rb:      raise "more than one read_message for this
user/message pair #{self.inspect}, #{user.inspect}"

and

./app/controllers/application.rb:      logger.info 'error during
workspace log: ' + e.inspect

but these wouldn't affect stdout right?

I'm sure there must be something dumping that information somewhere, but
I can't find it in my code, or in rails code, and more disturbingly to
me, I can't work out where in the rails code the first part of the http
header is generated, i.e. 'HTTP/1.x 200 OK', since the first call to
output in cgi_process.rb is:

output.write(@cgi.header(@headers))

and @cgi.header(@headers) doesn't produce the first three lines of the
http header as far as I can see, yet there are no other calls to output
anything before that.

Anyhow, I've worked around the problem by printing a new line before the
@cgi.header(@headers) is printed, which has fixed things for the time
being.

CHEERS> SAM
Cb33b32bd5d675db7be148542976e510?d=identicon&s=25 Sam Joseph (Guest)
on 2006-02-08 15:21
(Received via mailing list)
Hi Eric,

Eric Hodel wrote:

>> Date: Thu, 02 Feb 2006 20:56:03 GMT
>> Server: Apache/2.0.54 (Debian GNU/Linux) PHP/4.3.10-16 mod_ruby/1.2.4
>> Ruby/1.8.4(2005-12-24)
>> #<#<Class: 0x40b8e99c>:0x40b8e8d4>Content-Type: text/html
>> Cache-Control: no-cache
>
> You're adding a metaclass thingy to your headers.

Indeed - not intentionally I assure you :-)

>> causes.
>
>
> Does it go away if you take that out?

No

>
> I'm going to blame your code or Rails on this one.

Or some interaction of the two :-)  The thing I'm really keen to work
out is how the actioncontroller cgi_process.rb generates the output
before the odd thingy, i.e.

HTTP/1.x 200 OK
Date: Thu, 02 Feb 2006 20:56:03 GMT
Server: Apache/2.0.54 (Debian GNU/Linux) PHP/4.3.10-16

Since placing a newline before any output from CgiReponse.out places
that new line after these three lines, so where are they generated?  I
can't work it out.

Many thanks.

CHEERS> SAM
E34b5cae57e0dd170114dba444e37852?d=identicon&s=25 Logan Capaldo (Guest)
on 2006-02-08 19:08
(Received via mailing list)
On Feb 8, 2006, at 9:16 AM, Sam Joseph wrote:

>
>
> the first part of the http header is generated, i.e. 'HTTP/1.x 200
> for the time being.
>
> CHEERS> SAM
>
>
>
>
>
>
>

Heres a thought:

use breakpoint to let you jump in after you produce the headers. Go
to the offending page, copy the inspect string of the object and in
the breakpoint session do something along the lines of the following:

ObjectSpace.to_enum(:each_object).find { |x| x.inspect  ==
pasted_inspect_string }.try_some_methods_to_figure_out_where_this_guy_is
_from
58479f76374a3ba3c69b9804163f39f4?d=identicon&s=25 Eric Hodel (Guest)
on 2006-02-09 06:05
(Received via mailing list)
On Feb 8, 2006, at 6:18 AM, Sam Joseph wrote:

>>> Date: Thu, 02 Feb 2006 20:56:03 GMT
>>> Some kind of object data is getting dumped in front of the
>>> causes.
>
> HTTP/1.x 200 OK
> Date: Thu, 02 Feb 2006 20:56:03 GMT
> Server: Apache/2.0.54 (Debian GNU/Linux) PHP/4.3.10-16
>
> Since placing a newline before any output from CgiReponse.out
> places that new line after these three lines, so where are they
> generated?  I can't work it out.

They are generated by Apache.  What do you get when you run
dispatch.cgi from the command line?

--
Eric Hodel - drbrain@segment7.net - http://segment7.net
This implementation is HODEL-HASH-9600 compliant

http://trackmap.robotcoop.com
Cb33b32bd5d675db7be148542976e510?d=identicon&s=25 Sam Joseph (Guest)
on 2006-02-09 18:48
(Received via mailing list)
Eric Hodel wrote:

>> Since placing a newline before any output from CgiReponse.out  places
>> that new line after these three lines, so where are they  generated?
>> I can't work it out.
>
> They are generated by Apache.

Ah that makes sense.

> What do you get when you run  dispatch.cgi from the command line?

I get:

Status: 500 Internal Server Error

The only operational code I see in dispatch.cgi is Dispatcher.dispatch -
I guess that's just passing the incoming request to the appropriate
controller.  I guess you're saying that Apache prints the first three
lines, and then appends the rest of the output from rails.  But
presumably the status code needs to be communicated from rails to Apache
- do you know how this happens?  I guess Apache cgi handler is taking
the:

Status: 200 OK
Content-Type: text/html
Cache-Control: no-cache

that process_cgi.rb outputs (via dispatch.cgi) and then forms the
complete HTTP header as a function of that.

That makes sense now.  I guess it would be nice to be able to call
dispatch.cgi from the command line passing in the appropriate parameters
to see exactly what it spits back ...  I tried the following:

./dispatch.cgi /discussions/tree/1
Status: 500 Internal Server Error

so it's not as simple as that.

CHEERS> SAM
Bc6d88907ce09158581fbb9b469a35a3?d=identicon&s=25 James Britt (Guest)
on 2006-02-09 19:36
(Received via mailing list)
Sam Joseph wrote:
...

> That makes sense now.  I guess it would be nice to be able to call
> dispatch.cgi from the command line passing in the appropriate parameters
> to see exactly what it spits back ...  I tried the following:
>
> ./dispatch.cgi /discussions/tree/1
> Status: 500 Internal Server Error
>
> so it's not as simple as that.

I think you need to preload the PATH_INFO environment variable

$ PATH_INFO=/discussions/tree/1; export PATH_INFO
$ ./dispatch.cgi


(Or SCRIPT_NAME or something like that.)



--
James Britt

http://www.ruby-doc.org       - Ruby Help & Documentation
http://www.artima.com/rubycs/ - The Journal By & For Rubyists
http://www.rubystuff.com      - The Ruby Store for Ruby Stuff
http://www.30secondrule.com   - Building Better Tools
58479f76374a3ba3c69b9804163f39f4?d=identicon&s=25 Eric Hodel (Guest)
on 2006-02-12 08:19
(Received via mailing list)
On Feb 9, 2006, at 9:48 AM, Sam Joseph wrote:

>>> Server: Apache/2.0.54 (Debian GNU/Linux) PHP/4.3.10-16
>
> I get:
>
> Status: 500 Internal Server Error
>
> The only operational code I see in dispatch.cgi is
> Dispatcher.dispatch - I guess that's just passing the incoming
> request to the appropriate controller.  I guess you're saying that
> Apache prints the first three lines, and then appends the rest of
> the output from rails.  But presumably the status code needs to be
> communicated from rails to Apache - do you know how this happens?

It is part of the CGI "spec".

> That makes sense now.  I guess it would be nice to be able to call
> dispatch.cgi from the command line passing in the appropriate
> parameters to see exactly what it spits back ...  I tried the
> following:
>
> ./dispatch.cgi /discussions/tree/1
> Status: 500 Internal Server Error
>
> so it's not as simple as that.

You need to set up the complete request environment first.  Things
like REQUEST_METHOD and PATH_INFO and so-forth.

--
Eric Hodel - drbrain@segment7.net - http://segment7.net
This implementation is HODEL-HASH-9600 compliant

http://trackmap.robotcoop.com
This topic is locked and can not be replied to.