You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@couchdb.apache.org by Curt Arnold <ca...@apache.org> on 2009/06/18 16:07:17 UTC
Intermittent HTTP 500's
I've been seeing HTTP 500 failures from time to time with a fairly
recent snapshot build ("0.10.0a777361") from the SVN. The actual keys
have been omitted, however the queries have been working for a long
time and the keys are valid and return the right data most of the time.
Any clues what might be happening?
[Thu, 18 Jun 2009 01:22:59 GMT] [debug] [<0.1178.84>] 'POST' /loaded/
_design/query/_view/byURI?include_docs=true {1,1}
Headers: [{'Accept',"*/*"},
{'Accept-Encoding',"gzip, deflate"},
{'Accept-Language',"en-us"},
{'Cache-Control',"no-cache"},
{'Connection',"Keep-Alive"},
{'Content-Length',"537"},
{'Content-Type',"text/plain; charset=utf-8"},
{'Cookie',"x-auto-16=m%3Asize%7Cf%3A235.0"},
{'Host',"localhost:5984"},
{'Referer',"http://localhost:8888/browser/hosted.html?
browser"},
{'User-Agent',"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT
5.1; SV1; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR
3.5.30729; .NET CLR 1.1.4322)"}]
[Thu, 18 Jun 2009 01:22:59 GMT] [debug] [<0.1180.84>] 'GET' /loaded/
_design/query/_view/forSubject?include_docs=true;;key=[omitted] {1,
1
}
Headers: [{'Accept',"*/*"},
{'Accept-Encoding',"gzip, deflate"},
{'Accept-Language',"en-us"},
{'Cache-Control',"no-cache"},
{'Connection',"Keep-Alive"},
{'Cookie',"x-auto-16=m%3Asize%7Cf%3A235.0"},
{'Host',"localhost:5984"},
{'Referer',"http://localhost:8888/browser/hosted.html?
browser"},
{'User-Agent',"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT
5.1; SV1; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR
3.5.30729; .NET CLR 1.1.4322)"}]
[Thu, 18 Jun 2009 01:22:59 GMT] [debug] [<0.1180.84>] request_group
{Pid, Seq} {<0.15823.64>,4485}
[Thu, 18 Jun 2009 01:22:59 GMT] [info] [<0.1180.84>] 127.0.0.1 - -
'GET' /loaded/_design/query/_view/forSubject?
include_docs=true;;key=[omitted] 200
[Thu, 18 Jun 2009 01:22:59 GMT] [debug] [<0.1180.84>] 'GET' /loaded/
_design/query/_view/byURI?include_docs=true;key=[omitted] {1,
1
}
Headers: [{'Accept',"*/*"},
{'Accept-Encoding',"gzip, deflate"},
{'Accept-Language',"en-us"},
{'Cache-Control',"no-cache"},
{'Connection',"Keep-Alive"},
{'Cookie',"x-auto-16=m%3Asize%7Cf%3A235.0"},
{'Host',"localhost:5984"},
{'If-None-Match',"\"60FWBA3D7UUZI9NSMR4PS9VM4\""},
{'Referer',"http://localhost:8888/browser/hosted.html?
browser"},
{'User-Agent',"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT
5.1; SV1; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR
3.5.30729; .NET CLR 1.1.4322)"}]
[Thu, 18 Jun 2009 01:22:59 GMT] [debug] [<0.1180.84>] request_group
{Pid, Seq} {<0.15823.64>,4485}
[Thu, 18 Jun 2009 01:22:59 GMT] [info] [<0.1180.84>] 127.0.0.1 - -
'GET' /loaded/_design/query/_view/byURI?
include_docs=true;key=[omitted] 304
[Thu, 18 Jun 2009 01:23:09 GMT] [error] [<0.1178.84>] Uncaught error
in HTTP request: {exit,normal}
[Thu, 18 Jun 2009 01:23:09 GMT] [debug] [<0.1178.84>] Stacktrace:
[{mochiweb_request,recv,3},
{mochiweb_request,stream_unchunked_body,5},
{mochiweb_request,recv_body,2},
{couch_httpd,json_body,1},
{couch_httpd,json_body_obj,1},
{couch_httpd_view,handle_view_req,2},
{couch_httpd_db,do_db_req,2},
{couch_httpd,handle_request,5}]
[Thu, 18 Jun 2009 01:23:09 GMT] [debug] [<0.1178.84>] httpd 500 error
response:
{"error":"unknown_error","reason":"normal"}
[Thu, 18 Jun 2009 01:23:09 GMT] [info] [<0.1178.84>] 127.0.0.1 - -
'POST' /loaded/_design/query/_view/byURI?include_docs=true 500
[Thu, 18 Jun 2009 01:23:20 GMT] [debug] [<0.1180.84>] 'GET' /loaded/
_design/query/_view/forValue?key=[omitted] {1,
1
}
Headers: [{'Accept',"*/*"},
{'Accept-Encoding',"gzip, deflate"},
{'Accept-Language',"en-us"},
{'Connection',"Keep-Alive"},
{'Content-Type',"text/plain; charset=utf-8"},
{'Cookie',"x-auto-16=m%3Asize%7Cf%3A235.0"},
{'Host',"localhost:5984"},
{'If-None-Match',"\"60FWBA3D7UUZI9NSMR4PS9VM4\""},
{'Referer',"http://localhost:8888/browser/hosted.html?
browser"},
{'User-Agent',"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT
5.1; SV1; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR
3.5.30729; .NET CLR 1.1.4322)"}]
[Thu, 18 Jun 2009 01:23:20 GMT] [debug] [<0.1180.84>] request_group
{Pid, Seq} {<0.15823.64>,4485}
Re: Intermittent HTTP 500's
Posted by Brian Candler <B....@pobox.com>.
On Mon, Jun 22, 2009 at 07:44:45AM -0500, Curt Arnold wrote:
> The original post contained the CouchDB a representative section of
> couch.log, repeating part of it here:
>
> [Thu, 18 Jun 2009 01:22:59 GMT] [info] [<0.1180.84>] 127.0.0.1 - - 'GET'
> /loaded/_design/query/_view/byURI?include_docs=true;key=[omitted] 304
>
> [Thu, 18 Jun 2009 01:23:09 GMT] [error] [<0.1178.84>] Uncaught error in
> HTTP request: {exit,normal}
>
> [Thu, 18 Jun 2009 01:23:09 GMT] [debug] [<0.1178.84>] Stacktrace:
> [{mochiweb_request,recv,3},
> {mochiweb_request,stream_unchunked_body,5},
> {mochiweb_request,recv_body,2},
> {couch_httpd,json_body,1},
> {couch_httpd,json_body_obj,1},
> {couch_httpd_view,handle_view_req,2},
> {couch_httpd_db,do_db_req,2},
> {couch_httpd,handle_request,5}]
Sorry, my mistake for overlooking this. It still may be worth having a look
at the exchange with tcpdump or wireshark though, in case it sheds any
additional light.
Regards,
Brian.
Re: Intermittent HTTP 500's
Posted by Curt Arnold <ca...@apache.org>.
On Jun 22, 2009, at 4:11 AM, Brian Candler wrote:
> On Thu, Jun 18, 2009 at 11:23:35PM -0500, Curt Arnold wrote:
>> The problem only appears to occur in POST requests with multiple
>> keys.
>> I've added fallback behavior to my app to request the same data key
>> by
>> key which will work around the 500 error that occurs on the POST
>> request.
>
> Does the 500 error return any message in the body? You may be able to
> capture this using tcpdump. It may give a clue as to what's going on.
>
> If you are using CouchRest, the RestClient exception raised hides
> this body
> by default, but it is possible to capture it. Try something like this:
>
> begin
> ...
> rescue RestClient::ExceptionWithResponse => e
> resp = e.response
> STDERR.puts "#{resp.code} #{resp.message} #{resp.body}"
> end
>
> Also look in the couchdb log, usually under /usr/local/var/log/
> couchdb/, to
> see if there's any detail in there.
>
The original post contained the CouchDB a representative section of
couch.log, repeating part of it here:
[Thu, 18 Jun 2009 01:22:59 GMT] [info] [<0.1180.84>] 127.0.0.1 - -
'GET' /loaded/_design/query/_view/byURI?
include_docs=true;key=[omitted] 304
[Thu, 18 Jun 2009 01:23:09 GMT] [error] [<0.1178.84>] Uncaught error
in HTTP request: {exit,normal}
[Thu, 18 Jun 2009 01:23:09 GMT] [debug] [<0.1178.84>] Stacktrace:
[{mochiweb_request,recv,3},
{mochiweb_request,stream_unchunked_body,5},
{mochiweb_request,recv_body,2},
{couch_httpd,json_body,1},
{couch_httpd,json_body_obj,1},
{couch_httpd_view,handle_view_req,2},
{couch_httpd_db,do_db_req,2},
{couch_httpd,handle_request,5}]
[Thu, 18 Jun 2009 01:23:09 GMT] [debug] [<0.1178.84>] httpd 500 error
response:
{"error":"unknown_error","reason":"normal"}
[Thu, 18 Jun 2009 01:23:09 GMT] [info] [<0.1178.84>] 127.0.0.1 - -
'POST' /loaded/_design/query/_view/byURI?include_docs=true 500
Re: Intermittent HTTP 500's
Posted by Brian Candler <B....@pobox.com>.
On Thu, Jun 18, 2009 at 11:23:35PM -0500, Curt Arnold wrote:
> The problem only appears to occur in POST requests with multiple keys.
> I've added fallback behavior to my app to request the same data key by
> key which will work around the 500 error that occurs on the POST request.
Does the 500 error return any message in the body? You may be able to
capture this using tcpdump. It may give a clue as to what's going on.
If you are using CouchRest, the RestClient exception raised hides this body
by default, but it is possible to capture it. Try something like this:
begin
...
rescue RestClient::ExceptionWithResponse => e
resp = e.response
STDERR.puts "#{resp.code} #{resp.message} #{resp.body}"
end
Also look in the couchdb log, usually under /usr/local/var/log/couchdb/, to
see if there's any detail in there.
HTH,
Brian.
Re: Intermittent HTTP 500's
Posted by Curt Arnold <ca...@apache.org>.
On Jun 18, 2009, at 9:11 AM, Paul Davis wrote:
> Curt,
>
> Is it just me or do some of those URL's have semicolons where there
> should be ampersands? I don't think its necessarily relevant though.
> My first guess is that your client is closing the socket before the
> body has been completely sent.
>
> HTH,
> Paul Davis
>
Semicolons and ampersands should be equivalent, per the HTML 4.01
recommendation, semicolons are preferred since they do not require
escaping when they appear in HTML or XML documents.
The problem only appears to occur in POST requests with multiple
keys. I've added fallback behavior to my app to request the same data
key by key which will work around the 500 error that occurs on the
POST request.
I've observed failures when the request body is about 1000 characters,
possibly running into a problem with the request being too large or
perhaps the response is taking too long. The server message is no
help in understanding what could be going on without a knowledge of
CouchDB internals.
Re: Intermittent HTTP 500's
Posted by Paul Davis <pa...@gmail.com>.
Curt,
Is it just me or do some of those URL's have semicolons where there
should be ampersands? I don't think its necessarily relevant though.
My first guess is that your client is closing the socket before the
body has been completely sent.
HTH,
Paul Davis
On Thu, Jun 18, 2009 at 10:07 AM, Curt Arnold <ca...@apache.org> wrote:
>
> I've been seeing HTTP 500 failures from time to time with a fairly recent snapshot build ("0.10.0a777361") from the SVN. The actual keys have been omitted, however the queries have been working for a long time and the keys are valid and return the right data most of the time.
>
> Any clues what might be happening?
>
>
>
> [Thu, 18 Jun 2009 01:22:59 GMT] [debug] [<0.1178.84>] 'POST' /loaded/_design/query/_view/byURI?include_docs=true {1,1}
> Headers: [{'Accept',"*/*"},
> {'Accept-Encoding',"gzip, deflate"},
> {'Accept-Language',"en-us"},
> {'Cache-Control',"no-cache"},
> {'Connection',"Keep-Alive"},
> {'Content-Length',"537"},
> {'Content-Type',"text/plain; charset=utf-8"},
> {'Cookie',"x-auto-16=m%3Asize%7Cf%3A235.0"},
> {'Host',"localhost:5984"},
> {'Referer',"http://localhost:8888/browser/hosted.html?browser"},
> {'User-Agent',"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; .NET CLR 1.1.4322)"}]
>
> [Thu, 18 Jun 2009 01:22:59 GMT] [debug] [<0.1180.84>] 'GET' /loaded/_design/query/_view/forSubject?include_docs=true;;key=[omitted] {1,
> 1}
> Headers: [{'Accept',"*/*"},
> {'Accept-Encoding',"gzip, deflate"},
> {'Accept-Language',"en-us"},
> {'Cache-Control',"no-cache"},
> {'Connection',"Keep-Alive"},
> {'Cookie',"x-auto-16=m%3Asize%7Cf%3A235.0"},
> {'Host',"localhost:5984"},
> {'Referer',"http://localhost:8888/browser/hosted.html?browser"},
> {'User-Agent',"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; .NET CLR 1.1.4322)"}]
>
> [Thu, 18 Jun 2009 01:22:59 GMT] [debug] [<0.1180.84>] request_group {Pid, Seq} {<0.15823.64>,4485}
>
> [Thu, 18 Jun 2009 01:22:59 GMT] [info] [<0.1180.84>] 127.0.0.1 - - 'GET' /loaded/_design/query/_view/forSubject?include_docs=true;;key=[omitted] 200
>
> [Thu, 18 Jun 2009 01:22:59 GMT] [debug] [<0.1180.84>] 'GET' /loaded/_design/query/_view/byURI?include_docs=true;key=[omitted] {1,
> 1}
> Headers: [{'Accept',"*/*"},
> {'Accept-Encoding',"gzip, deflate"},
> {'Accept-Language',"en-us"},
> {'Cache-Control',"no-cache"},
> {'Connection',"Keep-Alive"},
> {'Cookie',"x-auto-16=m%3Asize%7Cf%3A235.0"},
> {'Host',"localhost:5984"},
> {'If-None-Match',"\"60FWBA3D7UUZI9NSMR4PS9VM4\""},
> {'Referer',"http://localhost:8888/browser/hosted.html?browser"},
> {'User-Agent',"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; .NET CLR 1.1.4322)"}]
>
> [Thu, 18 Jun 2009 01:22:59 GMT] [debug] [<0.1180.84>] request_group {Pid, Seq} {<0.15823.64>,4485}
>
> [Thu, 18 Jun 2009 01:22:59 GMT] [info] [<0.1180.84>] 127.0.0.1 - - 'GET' /loaded/_design/query/_view/byURI?include_docs=true;key=[omitted] 304
>
> [Thu, 18 Jun 2009 01:23:09 GMT] [error] [<0.1178.84>] Uncaught error in HTTP request: {exit,normal}
>
> [Thu, 18 Jun 2009 01:23:09 GMT] [debug] [<0.1178.84>] Stacktrace: [{mochiweb_request,recv,3},
> {mochiweb_request,stream_unchunked_body,5},
> {mochiweb_request,recv_body,2},
> {couch_httpd,json_body,1},
> {couch_httpd,json_body_obj,1},
> {couch_httpd_view,handle_view_req,2},
> {couch_httpd_db,do_db_req,2},
> {couch_httpd,handle_request,5}]
>
> [Thu, 18 Jun 2009 01:23:09 GMT] [debug] [<0.1178.84>] httpd 500 error response:
> {"error":"unknown_error","reason":"normal"}
>
>
> [Thu, 18 Jun 2009 01:23:09 GMT] [info] [<0.1178.84>] 127.0.0.1 - - 'POST' /loaded/_design/query/_view/byURI?include_docs=true 500
>
> [Thu, 18 Jun 2009 01:23:20 GMT] [debug] [<0.1180.84>] 'GET' /loaded/_design/query/_view/forValue?key=[omitted] {1,
> 1}
> Headers: [{'Accept',"*/*"},
> {'Accept-Encoding',"gzip, deflate"},
> {'Accept-Language',"en-us"},
> {'Connection',"Keep-Alive"},
> {'Content-Type',"text/plain; charset=utf-8"},
> {'Cookie',"x-auto-16=m%3Asize%7Cf%3A235.0"},
> {'Host',"localhost:5984"},
> {'If-None-Match',"\"60FWBA3D7UUZI9NSMR4PS9VM4\""},
> {'Referer',"http://localhost:8888/browser/hosted.html?browser"},
> {'User-Agent',"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; SV1; .NET CLR 2.0.50727; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729; .NET CLR 1.1.4322)"}]
>
> [Thu, 18 Jun 2009 01:23:20 GMT] [debug] [<0.1180.84>] request_group {Pid, Seq} {<0.15823.64>,4485}