Re: svn commit: r808679 - /couchdb/trunk/src/couchdb/couch_httpd.erl

[Adam Kocoloski]

Can we catch those errors and still log?  Or else duplicate all the  
info that was in the request log line in the response log line too?   
Trying to decipher this stuff is making my head hurt:

[info] [<0.5148.0>] 127.0.0.1 - 'POST' /test_suite_db
[info] [<0.5149.0>] 127.0.0.1 - 'GET' /test_suite_db/_all_docs
[info] [<0.5148.0>] Response code: 201
[info] [<0.5150.0>] 127.0.0.1 - 'POST' /test_suite_db
[info] [<0.5150.0>] Response code: 201
[info] [<0.5151.0>] 127.0.0.1 - 'POST' /test_suite_db
[info] [<0.5151.0>] Response code: 201
[info] [<0.5149.0>] Response code: 200
Following the Pids we realize that 1 goes with 3, 2 goes with 8, 4  
with 5, and 6 with 7.  And that was just two threads.  Best,

Adam

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, dam...@apache.org 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}),