[
https://issues.apache.org/jira/browse/COUCHDB-394?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12735695#action_12735695
]
Curt Arnold commented on COUCHDB-394:
-------------------------------------
I cloned my application and made the following modification to hopefully
provide more diagnostics of the underlying problem.
===================================================================
--- src/mochiweb/mochiweb_request.erl (revision 798196)
+++ src/mochiweb/mochiweb_request.erl (working copy)
@@ -121,6 +121,8 @@
case gen_tcp:send(Socket, Data) of
ok ->
ok;
+ { error, Reason } ->
+ exit(Reason);
_ ->
exit(normal)
end.
Was finally able to trigger the error and had the following in the log:
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] 'POST'
/loaded/_design/query/_view/byURI?include_docs=true {1,1}
Headers: [{'Accept',"text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2"},
{'Cache-Control',"no-cache"},
{'Connection',"keep-alive"},
{'Content-Length',"1373"},
{'Content-Type',"application/x-www-form-urlencoded"},
{'Host',"localhost:5984"},
{'Pragma',"no-cache"},
{'User-Agent',"Java/1.6.0_0"}]
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] request_group {Pid, Seq}
{<0.119.0>,4709}
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O284";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O209";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"d6490a8694d19768347dab5c62969b33">> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O182";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O187";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O229";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O20";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O248";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O225";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O2";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O204";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O201";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O133";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O32";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O12";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O251";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O192";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O174";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O290";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O238";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O197";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#acme";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O232";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O74";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] Include Doc:
<<"http://www.example.com/2009/03/schema#O114";>> nil
[Mon, 27 Jul 2009 16:45:55 GMT] [error] [<0.1162.0>] Uncaught error in HTTP
request: {exit,closed}
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] 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}]
[Mon, 27 Jul 2009 16:45:55 GMT] [debug] [<0.1162.0>] httpd 500 error response:
{"error":"unknown_error","reason":"closed"}
[Mon, 27 Jul 2009 16:45:55 GMT] [error] [<0.1162.0>] {error_report,<0.21.0>,
{<0.1162.0>,crash_report,
[[{pid,<0.1162.0>},
{registered_name,[]},
{error_info,
{exit,enotconn,
[{mochiweb_request,send,2},
{mochiweb_request,start_raw_response,2},
{mochiweb_request,respond,2},
{couch_httpd,send_response,4},
{couch_httpd,handle_request,5},
{mochiweb_http,headers,5},
{proc_lib,init_p,5}]}},
{initial_call,
{mochiweb_socket_server,acceptor_loop,
[{<0.54.0>,#Port<0.148>,#Fun<mochiweb_http.1.81679042>}]}},
{ancestors,
[couch_httpd,couch_secondary_services,couch_server_sup,
<0.1.0>]},
{messages,[]},
{links,[#Port<0.309>,<0.54.0>,#Port<0.308>]},
{dictionary,
[{mochiweb_request_body,
<<"{\"keys\":[\"http://www.example.com/2009/03/schema#O284\",\"http://www.example.com/2009/03/schema#O209\",\"urn:uuid:d6490a86-94d1-9768-347d-ab5c62969b33\",\"http://www.example.com/2009/03/schema#O182\",\"http://www.example.com/2009/03/schema#O187\",\"http://www.example.com/2009/03/schema#O229\",\"http://www.example.com/2009/03/schema#O20\",\"http://www.example.com/2009/03/schema#O248\",\"http://www.example.com/2009/03/schema#O225\",\"http://www.example.com/2009/03/schema#O2\",\"http://www.example.com/2009/03/schema#O204\",\"http://www.example.com/2009/03/schema#O201\",\"http://www.example.com/2009/03/schema#O133\",\"http://www.example.com/2009/03/schema#O32\",\"http://www.example.com/2009/03/schema#O12\",\"http://www.example.com/2009/03/schema#O251\",\"http://www.example.com/2009/03/schema#O192\",\"http://www.example.com/2009/03/schema#O174\",\"http://www.example.com/2009/03/schema#O290\",\"http://www.example.com/2009/03/schema#O238\",\"http://www.example.com/2009/03/schema#O197\",\"http://www.example.com/2009/03/schema#acme\",\"http://www.example.com/2009/03/schema#O232\",\"http://www.example.com/2009/03/schema#O74\",\"http://www.example.com/2009/03/schema#O114\"]}";>>},
{mochiweb_request_qs,[{"include_docs","true"}]},
{mochiweb_request_recv,true},
{jsonp,undefined},
{couch_drv_port,#Port<0.309>}]},
{trap_exit,false},
{status,running},
{heap_size,2584},
{stack_size,23},
{reductions,87159}],
[]]}}
[Mon, 27 Jul 2009 16:45:55 GMT] [error] [<0.54.0>] {error_report,<0.21.0>,
{<0.54.0>,std_error,
{mochiweb_socket_server,235,{child_error,enotconn}}}}
The corresponding code on the client side is:
new JSONObject(new JSONTokener(new BufferedReader(new
InputStreamReader(connection.getInputStream(), "utf-8"))));
In this particular failure, both the client and CouchDB are on the same
machine, so it is unlikely a problem with a network intermediary. The list of
fetched documents matches the expected response to the query (in this
particular instance, document IDs have a one-to-one correspondency with keys,
though that is not generally the case). Since all the documents were fetched
and the time between request and failure was less than a second, a timeout
seems unlikely.
If there was a problem with the decoding or parsing, it might have prematurely
closed the socket, resulting in the error.
Any thoughts?
> 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 [email protected] 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.
