fix(hooks): argspec not propagated for global hooks

The wrapped responder's argspec was not being propagated up through
the hooks, resulting in a misleading error message when a responder
raises TypeError.

falcon/api.py

@@ -17,6 +17,7 @@ limitations under the License.
 """
 
 import inspect
+import traceback
 
 from falcon.request import Request
 from falcon.response import Response
@@ -91,6 +92,11 @@ class API(object):
                 resp.body = ex.json()
 
         except TypeError as ex:
+            # NOTE(kgriffs): Get the stack trace up here since we can just
+            # use this convenience function which graps the last raised
+            # exception context.
+            stack_trace = traceback.format_exc()
+
             # See if the method doesn't support the given route's params, to
             # support assigning multiple routes to the same resource.
             try:
@@ -112,10 +118,13 @@ class API(object):
 
             # Does the responder require more or fewer args than given?
             if args_needed != args_given:
+                req.log_error('A responder method could not be found with the '
+                              'correct arguments.')
                 na_responder(req, resp)
             else:
                 # Error caused by something else
-                req.log_error('Responder raised TypeError: %s' % ex)
+                req.log_error('A responder method (on_*) raised TypeError. %s'
+                              % stack_trace)
                 falcon.responders.internal_server_error(req, resp)
 
         #

falcon/api_helpers.py

@@ -16,6 +16,7 @@ limitations under the License.
 
 """
 
+import inspect
 import re
 from functools import wraps
 
@@ -230,6 +231,13 @@ def _wrap_with_hooks(before, after, responder):
     return responder
 
 
+def _propagate_argspec(wrapper, responder):
+    if hasattr(responder, 'wrapped_argspec'):
+        wrapper.wrapped_argspec = responder.wrapped_argspec
+    else:
+        wrapper.wrapped_argspec = inspect.getargspec(responder)
+
+
 def _wrap_with_before(action, responder):
     """Execute the given action function before a bound responder.
 
@@ -245,6 +253,8 @@ def _wrap_with_before(action, responder):
         action(req, resp, kwargs)
         responder(req, resp, **kwargs)
 
+    _propagate_argspec(do_before, responder)
+
     return do_before
 
 
@@ -263,4 +273,6 @@ def _wrap_with_after(action, responder):
         responder(req, resp, **kwargs)
         action(req, resp)
 
+    _propagate_argspec(do_after, responder)
+
     return do_after

falcon/request.py

@@ -25,7 +25,7 @@ from falcon import util
 from falcon import request_helpers as helpers
 
 DEFAULT_ERROR_LOG_FORMAT = (u'{0:%Y-%m-%d %H:%M:%S} [FALCON] [ERROR]'
-                            u' {1} {2}?{3} => ')
+                            u' {1} {2}{3} => ')
 
 TRUE_STRINGS = ('true', 'True', 'yes')
 FALSE_STRINGS = ('false', 'False', 'no')
@@ -121,9 +121,15 @@ class Request(object):
 
         """
 
+        if self.query_string:
+            query_string_formatted = '?' + self.query_string
+        else:
+            query_string_formatted = ''
+
         log_line = (
             DEFAULT_ERROR_LOG_FORMAT.
-            format(datetime.now(), self.method, self.path, self.query_string)
+            format(datetime.now(), self.method, self.path,
+                   query_string_formatted)
         )
 
         if six.PY3:

falcon/tests/test_type_error.py

@@ -0,0 +1,72 @@
+import falcon
+import falcon.testing as testing
+
+
+class Thinger(object):
+    def __init__(self, number):
+        pass
+
+
+def teh_wrapper(req, resp, params):
+    pass
+
+
+class TypeErrornator(object):
+
+    def on_get(self, req, resp):
+        silly = True
+
+        # Call an uncallable
+        return silly()
+
+    def on_head(self, req, resp):
+        # Call with wrong number of arguments
+        Thinger()
+
+    def on_put(self, number):
+        # Responder has incorrect args
+        pass
+
+    def on_post(self, req, resp, user_id):
+        # Responder has incorrect args
+        Thinger()
+
+
+class TestTypeError(testing.TestBase):
+
+    def before(self):
+        self.api = falcon.API(before=teh_wrapper)
+        self.api.add_route('/typeerror', TypeErrornator())
+        self.api.add_route('/{user_id}/thingy', TypeErrornator())
+
+    def test_not_callable(self):
+        self.simulate_request('/typeerror')
+        self.assertEquals(self.srmock.status, falcon.HTTP_500)
+
+    def test_not_enough_init_args(self):
+        self.simulate_request('/typeerror', method='HEAD')
+        self.assertEquals(self.srmock.status, falcon.HTTP_500)
+
+    def test_responder_incorrect_argspec(self):
+        self.simulate_request('/typeerror', method='PUT')
+        self.assertEquals(self.srmock.status, falcon.HTTP_500)
+
+    def test_wrapped_not_enough_init_args(self):
+        self.simulate_request('/123/thingy', method='POST')
+        self.assertEquals(self.srmock.status, falcon.HTTP_500)
+
+    def test_double_wrapped_not_enough_init_args(self):
+        self.api = falcon.API(before=[teh_wrapper, teh_wrapper])
+        self.api.add_route('/typeerror', TypeErrornator())
+        self.api.add_route('/{user_id}/thingy', TypeErrornator())
+
+        self.simulate_request('/123/thingy', method='POST')
+        self.assertEquals(self.srmock.status, falcon.HTTP_500)
+
+    def test_triple_wrapped_not_enough_init_args(self):
+        self.api = falcon.API(before=[teh_wrapper, teh_wrapper, teh_wrapper])
+        self.api.add_route('/typeerror', TypeErrornator())
+        self.api.add_route('/{user_id}/thingy', TypeErrornator())
+
+        self.simulate_request('/123/thingy', method='POST')
+        self.assertEquals(self.srmock.status, falcon.HTTP_500)