Intermittent HTTP 500 errors on queries, no useful diagnostics --------------------------------------------------------------
Key: COUCHDB-394 URL: https://issues.apache.org/jira/browse/COUCHDB-394 Project: CouchDB Issue Type: Bug Components: HTTP Interface Affects Versions: 0.10 Environment: Ubuntu 8.10 on x386 on Amazon Web Services VM Reporter: Curt Arnold Originally raised on u...@couchdb.apache.org on 2009-06-16, but no resolution. Original message follows later. Analysis: seems like there is a failure during the call to gen_tcp:send, a connection dropped or something like that, however the calling code in mochiweb_request:send appears to discard the reason returned by gen_tcp:send leaving a user with no clue of the underlying problem. Here is Mochiweb_request:send send(Data) -> case gen_tcp:send(Socket, Data) of ok -> ok; _ -> exit(normal) end. In the case of a non ok return from gen_tcp:send, exit(normal) is called which is connected with the log file in the original message. It would seem much more helpful if the recent included in the return value from gen_tcp:send was passed to the exit/1 function. Actually, a different function appears in the original log file. I was looking at a slightly different entry in a different log file, but I think the analysis holds. Different log snippet: [Wed, 27 May 2009 00:39:00 GMT] [info] [<0.3318.13>] 127.0.0.1 - - 'GET' /default/_design/query/_view/byURI?include_docs=true;key=... 200 [Wed, 27 May 2009 00:39:00 GMT] [debug] [<0.3318.13>] 'GET' /default/_design/query/_view/byURI?include_docs=true;key=.. {1, 1} Headers: [{'Accept',"text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2"}, {'Connection',"keep-alive"}, {'Host',"localhost:5984"}, {'User-Agent',"Java/1.6.0_0"}] [Wed, 27 May 2009 00:39:00 GMT] [debug] [<0.3318.13>] request_group {Pid, Seq} {<0.3872.0>,1890} [Wed, 27 May 2009 00:39:00 GMT] [debug] [<0.3318.13>] Include Doc: <<"...">> nil [Wed, 27 May 2009 00:39:00 GMT] [error] [<0.3318.13>] Uncaught error in HTTP request: {exit,normal} [Wed, 27 May 2009 00:39:00 GMT] [debug] [<0.3318.13>] Stacktrace: [{mochiweb_request,send,2}, {couch_httpd,send_chunk,2}, {couch_httpd_view,design_doc_view,5}, {couch_httpd_db,do_db_req,2}, {couch_httpd,handle_request,5}, {mochiweb_http,headers,5}, {proc_lib,init_p,5}] [Wed, 27 May 2009 00:39:00 GMT] [debug] [<0.3332.13>] 'GET' /default/_design/query/_view/forSubject?include_docs=true;key=[] {1, 1} Headers: [{'Accept',"text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2"}, {'Connection',"keep-alive"}, {'Host',"localhost:5984"}, {'User-Agent',"Java/1.6.0_0"}] [Wed, 27 May 2009 00:39:00 GMT] [debug] [<0.3318.13>] httpd 500 error response: {"error":"unknown_error","reason":"normal"} [Wed, 27 May 2009 00:39:00 GMT] [debug] [<0.3332.13>] request_group {Pid, Seq} {<0.3872.0>,1890} [Wed, 27 May 2009 00:39:00 GMT] [debug] [<0.3332.13>] Include Doc: <<"...">> nil [Wed, 27 May 2009 00:39:00 GMT] [debug] [<0.3332.13>] Include Doc: <<"...">> nil ------ Original message: 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} -- This message is automatically generated by JIRA. - You can reply to this email to add a comment to the issue online.