+1 for single line logs. Not having the returned status code on the same line makes debugging logs quite a bit more difficult.
On Wed, Sep 16, 2009 at 1:06 PM, Adam Kocoloski <[email protected]> wrote: > Hi Damien, I'd _really_ still like to revert to one line in the logfile for > a request/response pair. I believe this patch does the trick; if you don't > object I'll apply it. Best, > > Adam > > diff --git a/src/couchdb/couch_httpd.erl b/src/couchdb/couch_httpd.erl > index 3518481..0c467d5 100644 > --- a/src/couchdb/couch_httpd.erl > +++ b/src/couchdb/couch_httpd.erl > @@ -135,7 +135,7 @@ handle_request(MochiReq, DefaultFun, > {FirstPart, _, _} -> > list_to_binary(FirstPart) > end, > - ?LOG_INFO("~s - ~p ~s", [ > + LogForClosedSocket = io_lib:format("socket was closed by ~s - ~p ~s", [ > MochiReq:get(peer), > MochiReq:get(method), > RawUri > @@ -184,6 +184,7 @@ handle_request(MochiReq, DefaultFun, > throw:{http_head_abort, Resp0} -> > {ok, Resp0}; > exit:normal -> > + ?LOG_INFO(LogForClosedSocket, []), > exit(normal); > throw:Error -> > ?LOG_DEBUG("Minor error in HTTP request: ~p",[Error]), > @@ -202,7 +203,12 @@ handle_request(MochiReq, DefaultFun, > ?LOG_INFO("Stacktrace: ~p",[erlang:get_stacktrace()]), > send_error(HttpReq, Error) > end, > - ?LOG_INFO("Response code: ~B", [Resp:get(code)]), > + ?LOG_INFO("~s - - ~p ~s ~B", [ > + MochiReq:get(peer), > + MochiReq:get(method), > + RawUri, > + Resp:get(code) > + ]), > RequestTime = round(timer:now_diff(now(), Begin)/1000), > couch_stats_collector:record({couchdb, request_time}, RequestTime), > couch_stats_collector:increment({httpd, requests}), > > On Aug 27, 2009, at 11:06 PM, Damien Katz wrote: > >> This way is more reliable for logging requests. Before this change, an >> error would occur if the client closed the connection (like when there is an >> error response) after the response is sent but before the LOG_INFO lines >> could be logged, then there would just be a big stack trace with none of the >> relevant connection information logged. >> >> -Damien >> >> On Aug 27, 2009, at 10:46 PM, Adam Kocoloski wrote: >> >>> Hi Damien, I'm -1 on writing the response code as a separate line in the >>> log file. I think it'll make parsing logfiles _really_ difficult, as the >>> request and response code lines aren't necessarily going to show up one >>> after the other. You'd have to match connection Pids, or something. Best, >>> >>> Adam >>> >>> On Aug 27, 2009, at 7:30 PM, [email protected] wrote: >>> >>>> Author: damien >>>> Date: Thu Aug 27 23:30:08 2009 >>>> New Revision: 808679 >>>> >>>> URL: http://svn.apache.org/viewvc?rev=808679&view=rev >>>> Log: >>>> Fixed spurious console errors caused when attempting to query >>>> information about an already closed socket. >>>> >>>> Modified: >>>> couchdb/trunk/src/couchdb/couch_httpd.erl >>>> >>>> Modified: couchdb/trunk/src/couchdb/couch_httpd.erl >>>> URL: >>>> http://svn.apache.org/viewvc/couchdb/trunk/src/couchdb/couch_httpd.erl?rev=808679&r1=808678&r2=808679&view=diff >>>> >>>> ============================================================================== >>>> --- couchdb/trunk/src/couchdb/couch_httpd.erl (original) >>>> +++ couchdb/trunk/src/couchdb/couch_httpd.erl Thu Aug 27 23:30:08 2009 >>>> @@ -135,9 +135,12 @@ >>>> {FirstPart, _, _} -> >>>> list_to_binary(FirstPart) >>>> end, >>>> - ?LOG_DEBUG("~p ~s ~p~nHeaders: ~p", [ >>>> + ?LOG_INFO("~s - ~p ~s", [ >>>> + MochiReq:get(peer), >>>> MochiReq:get(method), >>>> - RawUri, >>>> + RawUri >>>> + ]), >>>> + ?LOG_DEBUG("HTTP ~p~nHeaders: ~p", [ >>>> MochiReq:get(version), >>>> mochiweb_headers:to_list(MochiReq:get(headers)) >>>> ]), >>>> @@ -151,7 +154,6 @@ >>>> % possible (if any module references the atom, then it's existing). >>>> Meth -> couch_util:to_existing_atom(Meth) >>>> end, >>>> - >>>> increment_method_stats(Method1), >>>> % alias HEAD to GET as mochiweb takes care of stripping the body >>>> Method = case Method1 of >>>> @@ -173,7 +175,7 @@ >>>> {ok, Resp} = >>>> try >>>> case authenticate_request(HttpReq, AuthenticationFuns) of >>>> - Req when is_record(Req, httpd) -> >>>> + #httpd{} = Req -> >>>> HandlerFun(Req); >>>> Response -> >>>> Response >>>> @@ -181,6 +183,8 @@ >>>> catch >>>> throw:{http_head_abort, Resp0} -> >>>> {ok, Resp0}; >>>> + exit:normal -> >>>> + exit(normal); >>>> throw:Error -> >>>> ?LOG_DEBUG("Minor error in HTTP request: ~p",[Error]), >>>> ?LOG_DEBUG("Stacktrace: ~p",[erlang:get_stacktrace()]), >>>> @@ -198,13 +202,7 @@ >>>> ?LOG_INFO("Stacktrace: ~p",[erlang:get_stacktrace()]), >>>> send_error(HttpReq, Error) >>>> end, >>>> - >>>> - ?LOG_INFO("~s - - ~p ~s ~B", [ >>>> - MochiReq:get(peer), >>>> - MochiReq:get(method), >>>> - RawUri, >>>> - Resp:get(code) >>>> - ]), >>>> + ?LOG_INFO("Response code: ~B", [Resp:get(code)]), >>>> RequestTime = round(timer:now_diff(now(), Begin)/1000), >>>> couch_stats_collector:record({couchdb, request_time}, RequestTime), >>>> couch_stats_collector:increment({httpd, requests}), >>>> >>>> >>> >> > >
