400 bad request

this is nginx 0.6.34. We run some fairly high volume facebook sites and
have had problems with 400 errors now for months. It only happens on
one part of our site that runs inside an iframe. At first I thought it
was cookies that were too large. I increased some of the buffers but
that didn’t appear to make any difference. A couple of days ago we took
out all the code that was generating large cookies, and are still
getting 400 errors. The really frustrating part is that nginx refuses
to log the error, so we can’t even debug it properly.

This is with nginx as a reverse proxy for rails.

Chris

Posted at Nginx Forum:

So, who is generating the 400 error ? Nginx, or is it the Mongrel
behind it ? Mongrel has a very pedantic parser, which itself will slam
the door on a request it considers badly formed.

ps. Appologies if you are not running rails behind nginx.

Cheers

Dave

It’s not mongrel, although I dont’ know for sure if mongrel wouldn’t
also choke on whatever nginx is choking on if nginx actually passed it
through.

Chris

Posted at Nginx Forum:

error_log /path/to/error.log info;

More: Module ngx_http_core_module

Is there a way to force nginx to log 400 errors? At least then I could
debug this better. It’s been difficult to find specific triggers. The
one common trigger is that it only happens in a facebook connect iframe.
We have a situation where two facebook connect iframes are loaded from
our domain on the same page, and that triggers it around 80% of the
time. My best guess at this point is that it’s a bug with cookie
headers.

chris

Posted at Nginx Forum:

If you can reproduce the problem then get out ngrep and check out
exactly
what is being sent on the wire.

When you say ‘Is there a way to force nginx to log 400 errors’, are they
showing up in your access logs ?

Cheers

Dave

snacktime writes:

I just turned up the error log level to debug and nginx still won’t log
these. It’s definitely generating them though.

Posted at Nginx Forum:

nginx doesn’t log these errors for some reason. They don’t show up in
the access or error log, and we have both turned on. If I could look at
the raw data I could figure out if it’s facebook that’s breaking a spec
somewhere, or if it’s an nginx bug. We have narrowed it down to being
specifically a cookie issue. More specifically it’s facebook connect
that sets the cookies nginx bombs on.

Posted at Nginx Forum:

Can you post a tshark, tcpdump -s 0 or ngrep to show the problem ?

So, to confirm, there is no record of the request at all in your
access log? But facebook is telling you that it could not contact your
servers (sorry, I have no experience with writing facebook apps) ?

Can you ngrep the request coming from facebook to confirm that it is
hitting your server ?

Dave C. Wrote:

So, to confirm, there is no record of the request
at all in your
access log?

Nothing. I set the log level on the error log to debug also to see if
that would force something into the error logs, but nothing.

But facebook is telling you that it

could not contact your
servers (sorry, I have no experience with writing
facebook apps) ?

I’ll try to explain as best I can. The request that generates the
errors is not going through facebook, that’s how we know it’s nginx
because the page displays the raw nginx error page with the nginx
version number and all. That page is inside an iframe on a facebook
canvas page. The iframe loads pages directly from our server. Inside
the iframe is also some fb javascript code that loads a proxy file from
our server directly to handle cross domain iframe communications, and at
the same time sets cookies on our domain. We think it’s the facebook
javascript code we are running in our iframe that is setting the cookies
that nginx doesn’t like. We are pretty sure about this because some of
the banner ads we run on other pages of our site are also facebook
connect iframes, and they also have the same effect. Once they set a
bad cookie, all the images on the facebook canvas which reference our
servers start to break due to 400 responses.

Chris

Posted at Nginx Forum:

So, here is what I get on my nginx when I submit a bad request

[root@odessa ~]# nginx -v
nginx version: nginx/0.7.31

moriarty:~ dave$ telnet odessa.cheney.net 80
Trying 64.85.168.249…
Connected to odessa.cheney.net.
Escape character is ‘^]’.
GET $ HTTP/1.1

400 Bad Request

400 Bad Request


nginx Connection closed by foreign host.

==> /var/log/nginx/access.log <==
203.166.242.201 odessa.cheney.net - [12/Jun/2009:22:18:41 -0400] “-”
400 166 “-” “-”

If you are receiving nothing in your logs then my next suggestion is
to get out ngrep and sniff the wire traffic

[root@odessa ~]# ngrep -d eth0 port 80
interface: eth0 (64.85.160.0/255.255.240.0)

T 203.166.242.201:55162 → 64.85.168.249:80 [AP]
GET $ HTTP/1.1…

T 64.85.168.249:80 → 203.166.242.201:55162 [AP]

..400 Bad Request....

400 Bad Request

..
nginx...... ######## T 65.55.232.48:63090 -> 64.85.168.249:80 [A]

If you can post the results of your ngrep, I might be able to suggest
something.

Cheers

Dave

Well I figured out exactly what causes this after getting someone that
had the errors to install the firefox livehttpheaders plugin. It’s the
cookie size. Cookie too large, nginx returns a 400 and doesn’t log it.
Unfortunately there isn’t much we can do about the cookie size. With
the fb connect iframe stuff there are other parties setting cookies on
our domain.

I tried in the past upping some buffers because I thought this might
possibly be an issue, but it didn’t help. Maybe I set the wrong ones.
What specific setting can I use to allow large cookie headers?

Below is a session of one of the requests causing the error:

GET
/forums?facebook=1&token=56be59ba413134e28e2976e35545960c&user_id=8&app_name=mogul&fb_sig_in_iframe=1&fb_sig_locale=en_US&fb_sig_in_new_facebook=1&fb_sig_time=1244858147.2827&fb_sig_added=1&fb_sig_profile_update_time=1232413305&fb_sig_expires=0&fb_sig_user=542007204&fb_sig_session_key=deec04765ed50ee023ae5cf1-542007204&fb_sig_ext_perms=offline_access%2Cemail%2Cauto_publish_recent_activity&fb_sig_api_key=cf73a4d662d5ce97b44ec8a9f3121c9d&fb_sig_app_id=15420082636&fb_sig=b88fd355c67517fb5d67230415750609
HTTP/1.1
Host: facebook.offbeat-creations.com
User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.0.11)
Gecko/2009060215 Firefox/3.0.11
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,/;q=0.8
Accept-Language: en-us
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive
Referer: Log into Facebook
Cookie:
__utma=131917208.1556222345328091100.1244852730.1244856612.1244858119.3;
__utmz=131917208.1244858119.3.3.utmcsr=apps.facebook.com|utmccn=(referral)|utmcmd=referral|utmcct=/beatycoon/;
user_542007204=%5B%7B%22activities%22%3A%22%22%2C%22affiliations%22%3A%5B%7B%22nid%22%3A67108883%2C%22name%22%3A%22Seattle%2C%20WA%22%2C%22type%22%3A%22region%22%2C%22status%22%3A%22%22%2C%22year%22%3A0%7D%5D%2C%22birthday%22%3A%22December%2024%22%2C%22books%22%3A%22%22%2C%22current_location%22%3A%7B%22zip%22%3A%22%22%7D%2C%22education_history%22%3A%7B%7D%2C%22first_name%22%3A%22Chia%20Chin%22%2C%22interests%22%3A%22%22%2C%22meeting_for%22%3A%7B%7D%2C%22meeting_sex%22%3A%7B%7D%2C%22movies%22%3A%22%22%2C%22music%22%3A%22%22%2C%22name%22%3A%22Chia%20Chin%20Lee%22%2C%22pic%22%3A%22http%3A//profile.ak.facebook.com/profile5/772/114/s542007204_148.jpg%22%2C%22pic_small%22%3A%22http%3A//profile.ak.facebook.com/profile5/772/114/t542007204_148.jpg%22%2C%22relationship_status%22%3A%22Married%22%2!
C%22religion%22%3A%22%22%2C%22sex%22%3A%22male%22%2C%22status%22%3A%7B%22message%22%3A%22%22%2C%22time%22%3A0%2C%22status_id%22%3A0%7D%2C%22tv%22%3A%22%22%2C%22uid%22%3A542007204%2C%22wall_count%22%3A305%2C%22work_history%22%3A%7B%7D%2C%22pic_square%22%3A%22http%3A//profile.ak.facebook.com/profile5/772/114/q542007204_148.jpg%22%7D%5D;
gtl=131174;
photos_542007204=%5B%7B%22subject%22%3A%22565010917%22%7D%2C%7B%22subject%22%3A%22603403123%22%7D%2C%7B%22subject%22%3A%22604053658%22%7D%2C%7B%22subject%22%3A%22636124705%22%7D%2C%7B%22subject%22%3A%22639286473%22%7D%2C%7B%22subject%22%3A%22644531360%22%7D%2C%7B%22subject%22%3A%22679766796%22%7D%2C%7B%22subject%22%3A%22700195562%22%7D%2C%7B%22subject%22%3A%22708288958%22%7D%2C%7B%22subject%22%3A%22708288958%22%7D%2C%7B%22subject%22%3A%22746248293%22%7D%2C%7B%22subject%22%3A%22746248293%22%7D%2C%7B%22subject%22%3A%22757564008%22%7D%2C%7B%22subject%22%3A%221165467950%22%7D%2C%7B%22subject%22%3A%221165467950%22%7D%2C%7B%22subject%22%!
3A%221165467950%22%7D%2C%7B%22subject%22%3A%221182339204%22%7D!
%2C%7B%2
2subject%22%3A%221223236240%22%7D%2C%7B%22subject%22%3A%221223236240%22%7D%2C%7B%22subject%22%3A%221223236240%22%7D%2C%7B%22subject%22%3A%221303717901%22%7D%2C%7B%22subject%22%3A%221303717901%22%7D%2C%7B%22subject%22%3A%221313378551%22%7D%2C%7B%22subject%22%3A%221313378551%22%7D%2C%7B%22subject%22%3A%221347486368%22%7D%2C%7B%22subject%22%3A%221347486368%22%7D%2C%7B%22subject%22%3A%221347486368%22%7D%2C%7B%22subject%22%3A%221444025780%22%7D%2C%7B%22subject%22%3A%221507201538%22%7D%2C%7B%22subject%22%3A%221536746061%22%7D%2C%7B%22subject%22%3A%221536746061%22%7D%2C%7B%22subject%22%3A%221536746061%22%7D%5D;
__utmb=131917208.4.7.1244858119139; __utmc=131917208;
mogul_game_session=BAh7DTogX3JmYWNlYm9va19mYnNlc3Npb25faG9sZGVydToiUkZhY2Vib29rOjpGYWNlYm9va1dlYlNlc3Npb24CFAEECHsPIhhAbGFzdF9lcnJvcl9tZXNzYWdlMCILQHF1aWV0RiIQQGFwaV9zZWNyZXQiJWRjM2E5OTAxZDVkNTYxOWRjOGMzYzllMGE5OTcxMjkyIg1AbmV0d29yayINZmFjZWJvb2siEUBzZXNzaW9uX2tleSInZGVlYzA0NzY1ZWQ1MGVlMDIzYWU1Y2YxLTU0MjAwNzIwNCIVQHNlc3Np!
b25fZXhwaXJlcyIGMCIVQHNlc3Npb25fdXNlcl9pZCIONTQyMDA3MjA0IhVAbGFzdF9lcnJvcl9jb2RlMCINQGFwaV9rZXkiJWNmNzNhNGQ2NjJkNWNlOTdiNDRlYzhhOWYzMTIxYzlkIg1AZXhwaXJlZEY6D2ZvcnVtX3BhZ2UwIg1hcHBfbmFtZSIKbW9ndWwiDHVzZXJfaWQiBjgiCmZsYXNoSUM6J0FjdGlvbkNvbnRyb2xsZXI6OkZsYXNoOjpGbGFzaEhhc2h7AAY6CkB1c2VkewA6GF9yZmFjZWJvb2tfZmJwYXJhbXN7ESIJdXNlciIONTQyMDA3MjA0IgphZGRlZCIGMSIQc2Vzc2lvbl9rZXkiJ2RlZWMwNDc2NWVkNTBlZTAyM2FlNWNmMS01NDIwMDcyMDQiGHByb2ZpbGVfdXBkYXRlX3RpbWUiDzEyMzI0MTMzMDUiDGV4cGlyZXMiBjAiFGluX25ld19mYWNlYm9vayIGMSIJdGltZSIUMTI0NDg1ODEyMi4xNzM0IgxhcGlfa2V5IiVjZjczYTRkNjYyZDVjZTk3YjQ0ZWM4YTlmMzEyMWM5ZCIOZXh0X3Blcm1zIjZvZmZsaW5lX2FjY2VzcyxlbWFpbCxhdXRvX3B1Ymxpc2hfcmVjZW50X2FjdGl2aXR5IgthcHBfaWQiEDE1NDIwMDgyNjM2Igtsb2NhbGUiCmVuX1VTIg5pbl9pZnJhbWUiBjEiDWZhY2Vib29rIgYxOgl0ZXN0IhNUSElTIElTIEEgVEVTVA%3D%3D–c75e1ae9b191ce2f330ce702f2549ece203baff8;
fbsetting_cf73a4d662d5ce97b44ec8a9f3121c9d=%7B%22connectState%22%3A1%2C%22oneLineStorySetting%22%3A1%2C%22shortStorySetting%22%3A1%2C%22inFacebook%2!
2%3Atrue%7D; cf73a4d662d5ce97b44ec8a9f3121c9d=dca5f61a4d674f57!
b6ce07e3
e1261045; cf73a4d662d5ce97b44ec8a9f3121c9d_user=542007204;
cf73a4d662d5ce97b44ec8a9f3121c9d_ss=d867120f5c1cc5eac268e3cdae6c43cc;
cf73a4d662d5ce97b44ec8a9f3121c9d_session_key=deec04765ed50ee023ae5cf1-542007204;
cf73a4d662d5ce97b44ec8a9f3121c9d_expires=0

HTTP/1.x 400 Bad Request
Server: nginx/0.6.34
Date: Sat, 13 Jun 2009 01:55:53 GMT
Content-Type: text/html
Content-Length: 173
Connection: close

Posted at Nginx Forum:

snacktime wrote:

Well I figured out exactly what causes this after getting someone that had the errors to install the firefox livehttpheaders plugin. It’s the cookie size. Cookie too large, nginx returns a 400 and doesn’t log it. Unfortunately there isn’t much we can do about the cookie size. With the fb connect iframe stuff there are other parties setting cookies on our domain.

I tried in the past upping some buffers because I thought this might possibly be an issue, but it didn’t help.

Which buffers did you set?

Maybe I set the wrong ones. What specific setting can I use to allow large cookie headers?

You probably need to adjust client_header_buffer_size and
large_client_header_buffers.

See Module ngx_http_core_module
and
Module ngx_http_core_module

/
Jim

you might look into increasing large_client_header_buffers so the
buffer is large enough to hold the cookie.

http://wiki.nginx.org/NginxHttpCoreModule#large_client_header_buffers

V/r,
Rob S.