fix(Request): UTF-8 logging

falcon/request.py

@@ -16,12 +16,15 @@ limitations under the License.
 
 """
 
-import sys
 from datetime import datetime
 
+import six
+
 from falcon.request_helpers import *
 from falcon.exceptions import *
-import six
+
+DEFAULT_ERROR_LOG_FORMAT = ('{0:%Y-%m-%d %H:%M:%S} [FALCON] [ERROR]'
+                            ' {1} {2}?{3} => {4}\n')
 
 
 class Request(object):
@@ -50,21 +53,23 @@ class Request(object):
 
         """
 
-        self.app = env['SCRIPT_NAME']
+        self._wsgierrors = env['wsgi.errors']
         self.body = env['wsgi.input']
+
+        self.protocol = env['wsgi.url_scheme']
+        self.app = env['SCRIPT_NAME']
         self.method = env['REQUEST_METHOD']
         self.path = env['PATH_INFO'] or '/'
-        self.protocol = env['wsgi.url_scheme']
         self.query_string = query_string = env['QUERY_STRING']
+
         self._params = parse_query_string(query_string)
         self._headers = parse_headers(env)
-        self._wsgierrors = env['wsgi.errors']
 
     def log_error(self, message):
         """Log an error to wsgi.error
 
-        Prepends timestamp and request info to message, and writes the result
-        out to the WSGI server's error stream (wsgi.error).
+        Prepends timestamp and request info to message, and writes the
+        result out to the WSGI server's error stream (wsgi.error).
 
         Args:
             message: A string describing the problem. If a byte-string and
@@ -72,11 +77,13 @@ class Request(object):
                 as UTF-8.
 
         """
-        u = six.text_type
+        if not six.PY3 and isinstance(message, unicode):
+            message = message.encode('utf-8')
+
         log_line = (
-            u('{0:%Y-%m-%d %H:%M:%S} [FALCON] [ERROR] {1} {2}?{3} => {4}\n').
-            format(datetime.now(), self.method, self.path, self.query_string,
-                   message)
+            DEFAULT_ERROR_LOG_FORMAT.
+            format(datetime.now(), self.method, self.path,
+                   self.query_string, message)
         )
 
         self._wsgierrors.write(log_line)

tests/dump_wsgi.py

@@ -1,4 +1,11 @@
+import pdb
+from wsgiref.simple_server import make_server
+
+
 def application(environ, start_response):
+    wsgi_errors = environ['wsgi.errors']
+    pdb.set_trace()
+
     start_response("200 OK", [
         ('Content-Type', 'text/plain')])
 
@@ -13,9 +20,7 @@ def application(environ, start_response):
 
 app = application
 
-if __name__ == '__main__':
-    import wsgiref
-    from wsgiref.simple_server import make_server
 
+if __name__ == '__main__':
     server = make_server('localhost', 8000, application)
     server.serve_forever()

tests/test_wsgi_errors.py

@@ -1,14 +1,13 @@
 import io
-import sys
+import six
 from . import helpers
 
-
 unicode_message = u'Unicode: \x80'
 
-if sys.version_info[0] == 2:
-    str_message = 'UTF-8: \xc2\x80'
-else:
+if six.PY3:
     str_message = 'Unicode all the way: \x80'
+else:
+    str_message = 'UTF-8: \xc2\x80'
 
 
 class BombResource:
@@ -37,31 +36,46 @@ class TestWSGIError(helpers.TestSuite):
 
         self.api.add_route('/bomb', self.tehbomb)
         self.api.add_route('/logger', self.tehlogger)
-        self.wsgierrors = io.StringIO()
+
+        self.wsgierrors_buffer = io.BytesIO()
+
+        if six.PY3:
+            # Simulate Gunicorn's behavior under Python 3
+            self.wsgierrors = io.TextIOWrapper(self.wsgierrors_buffer,
+                                               line_buffering=True)
+        else:
+            # WSGI servers typically present an open file object,
+            # with undefined encoding, so do the encoding manually.
+            self.wsgierrors = self.wsgierrors_buffer
 
     def test_exception_logged(self):
         self._simulate_request('/bomb', wsgierrors=self.wsgierrors)
-        log = self.wsgierrors.getvalue()
 
-        self.assertIn('IOError', log)
+        log = self.wsgierrors_buffer.getvalue()
+        self.assertIn(b'IOError', log)
 
     def test_exception_logged_with_details(self):
         self._simulate_request('/bomb', wsgierrors=self.wsgierrors,
                                method='HEAD')
-        log = self.wsgierrors.getvalue()
 
-        self.assertIn('MemoryError', log)
-        self.assertIn('remember a thing', log)
+        log = self.wsgierrors_buffer.getvalue()
+
+        self.assertIn(b'MemoryError', log)
+        self.assertIn(b'remember a thing', log)
 
     def test_responder_logged_unicode(self):
         self._simulate_request('/logger', wsgierrors=self.wsgierrors)
 
-        log = self.wsgierrors.getvalue()
-        self.assertIn(unicode_message, log)
+        log = self.wsgierrors_buffer.getvalue()
+        self.assertIn(unicode_message.encode('utf-8'), log)
 
     def test_responder_logged_str(self):
         self._simulate_request('/logger', wsgierrors=self.wsgierrors,
                                method='HEAD')
 
-        log = self.wsgierrors.getvalue()
-        self.assertIn(str_message, log)
+        log = self.wsgierrors_buffer.getvalue()
+
+        if six.PY3:
+            self.assertIn(str_message.encode('utf-8'), log)
+        else:
+            self.assertIn(str_message, log)

tox.ini

@@ -1,7 +1,8 @@
 [tox]
-envlist = py27,py32
+envlist = py27,py33
+deps = -r{toxinidir}/tests/requirements.txt
 
 [testenv]
-deps = -r{toxinidir}/requirements.txt
+deps = -r{toxinidir}/tests/requirements.txt
 
 commands = nosetests --with-progressive