[tor-commits] [stem/master] Reducing socket/proctol error logging to INFO

[atagar at torproject.org]

commit ad77d82535a5d86cb9b059d2365ff70cfa260c53
Author: Damian Johnson <atagar at torproject.org>
Date:   Sun Jan 1 10:12:18 2012 -0800

    Reducing socket/proctol error logging to INFO
    
    The base socket and protocol errors are too low level to be of interest to
    users. They're interested in the symptoms and what it means for them not that,
    say, a control message was malformed.
    
    Also escaping the logged message content - much easier to make sense of that
    way.
---
 stem/socket.py   |   14 +++++++-------
 stem/util/log.py |   17 +++++++++++++++++
 2 files changed, 24 insertions(+), 7 deletions(-)

diff --git a/stem/socket.py b/stem/socket.py
index 961fece..b2bde2b 100644
--- a/stem/socket.py
+++ b/stem/socket.py
@@ -697,13 +697,13 @@ def recv_message(control_file):
       # if the control_file has been closed then we will receive:
       # AttributeError: 'NoneType' object has no attribute 'recv'
       
-      log.warn("SocketClosed: socket file has been closed")
+      log.info("SocketClosed: socket file has been closed")
       raise SocketClosed("socket file has been closed")
     except socket.error, exc:
       # when disconnected we get...
       # socket.error: [Errno 107] Transport endpoint is not connected
       
-      log.warn("SocketClosed: received an exception (%s)" % exc)
+      log.info("SocketClosed: received an exception (%s)" % exc)
       raise SocketClosed(exc)
     
     raw_content += line
@@ -715,16 +715,16 @@ def recv_message(control_file):
       # if the socket is disconnected then the readline() method will provide
       # empty content
       
-      log.warn("SocketClosed: empty socket content")
+      log.info("SocketClosed: empty socket content")
       raise SocketClosed("Received empty socket content.")
     elif len(line) < 4:
-      log.warn("ProtocolError: line too short (%s)" % line)
+      log.info("ProtocolError: line too short (%s)" % log.escape(line))
       raise ProtocolError("Badly formatted reply line: too short")
     elif not re.match(r'^[a-zA-Z0-9]{3}[-+ ]', line):
-      log.warn("ProtocolError: malformed status code/divider (%s)" % line)
+      log.info("ProtocolError: malformed status code/divider (%s)" % log.escape(line))
       raise ProtocolError("Badly formatted reply line: beginning is malformed")
     elif not line.endswith("\r\n"):
-      log.warn("ProtocolError: no CRLF linebreak (%s)" % line)
+      log.info("ProtocolError: no CRLF linebreak (%s)" % log.escape(line))
       raise ProtocolError("All lines should end with CRLF")
     
     line = line[:-2] # strips off the CRLF
@@ -754,7 +754,7 @@ def recv_message(control_file):
         raw_content += line
         
         if not line.endswith("\r\n"):
-          log.warn("ProtocolError: no CRLF linebreak for data entry (%s)" % line)
+          log.info("ProtocolError: no CRLF linebreak for data entry (%s)" % log.escape(line))
           raise ProtocolError("All lines should end with CRLF")
         elif line == ".\r\n":
           break # data block termination
diff --git a/stem/util/log.py b/stem/util/log.py
index 76ebb2c..f9efa09 100644
--- a/stem/util/log.py
+++ b/stem/util/log.py
@@ -89,3 +89,20 @@ def notice(message): log(Runlevel.NOTICE, message)
 def warn(message):   log(Runlevel.WARN, message)
 def error(message):  log(Runlevel.ERROR, message)
 
+def escape(message):
+  """
+  Escapes specific sequences for logging (newlines, tabs, carrage returns).
+  
+  Arguments:
+    message (str) - string to be escaped
+  
+  Returns:
+    str that is escaped
+  """
+  
+  for pattern, replacement in (("\n", "\\n"), ("\r", "\\r"), ("\t", "\\t")):
+    message = message.replace(pattern, replacement)
+  
+  return message
+
+