Lower log level of errors caused by user requests to INFO

When webob exception is returned, error level log is
always recorded even though we return 4xx (client error)
to users. 4xx error in response code means errors due to
user requests, so error level log is not appropriate.
This commit lowers the log level to INFO for such events.

Currently only case I see is webob.exc.HTTPNotFound returned
by the policy engine when a user requests an operation
prohibited by the policy, but I think there is no reason
we deal with 404 specially in neutron.api.v2.resource.

Change-Id: I9f042a90c9bf528be7cb835d7fe818ed1879054b
Closes-Bug: #1473556

diff --git a/neutron/api/v2/resource.py b/neutron/api/v2/resource.py
index 2fd66d1a4e92a7fcedb01398fba70dbfae9ceec0..ac999465024bd0f05fb7ca2a6ce39bc575920acc 100644 (file)
--- a/neutron/api/v2/resource.py
+++ b/neutron/api/v2/resource.py
@@ -102,7 +102,11 @@ def Resource(controller, faults=None, deserializers=None, serializers=None):
             raise mapped_exc(**kwargs)
         except webob.exc.HTTPException as e:
             type_, value, tb = sys.exc_info()
-            LOG.exception(_LE('%s failed'), action)
+            if hasattr(e, 'code') and 400 <= e.code < 500:
+                LOG.info(_LI('%(action)s failed (client error): %(exc)s'),
+                         {'action': action, 'exc': e})
+            else:
+                LOG.exception(_LE('%s failed'), action)
             translate(e, language)
             value.body = serializer.serialize(
                 {'NeutronError': get_exception_data(e)})

diff --git a/neutron/tests/unit/api/v2/test_resource.py b/neutron/tests/unit/api/v2/test_resource.py
index 96c7d2da29d1b6d8dce0773a0abc383e2071e4f5..36afc95572efcb3ee0b6138517988d8a0623f75b 100644 (file)
--- a/neutron/tests/unit/api/v2/test_resource.py
+++ b/neutron/tests/unit/api/v2/test_resource.py
@@ -289,19 +289,21 @@ class ResourceTestCase(base.BaseTestCase):
         res = resource.delete('', extra_environ=environ)
         self.assertEqual(res.status_int, 204)
 
-    def _test_error_log_level(self, map_webob_exc, expect_log_info=False,
-                              use_fault_map=True):
-        class TestException(n_exc.NeutronException):
-            message = 'Test Exception'
+    def _test_error_log_level(self, expected_webob_exc, expect_log_info=False,
+                              use_fault_map=True, exc_raised=None):
+        if not exc_raised:
+            class TestException(n_exc.NeutronException):
+                message = 'Test Exception'
+            exc_raised = TestException
 
         controller = mock.MagicMock()
-        controller.test.side_effect = TestException()
-        faults = {TestException: map_webob_exc} if use_fault_map else {}
+        controller.test.side_effect = exc_raised()
+        faults = {exc_raised: expected_webob_exc} if use_fault_map else {}
         resource = webtest.TestApp(wsgi_resource.Resource(controller, faults))
         environ = {'wsgiorg.routing_args': (None, {'action': 'test'})}
         with mock.patch.object(wsgi_resource, 'LOG') as log:
             res = resource.get('', extra_environ=environ, expect_errors=True)
-            self.assertEqual(res.status_int, map_webob_exc.code)
+            self.assertEqual(res.status_int, expected_webob_exc.code)
         self.assertEqual(expect_log_info, log.info.called)
         self.assertNotEqual(expect_log_info, log.exception.called)
 
@@ -316,6 +318,16 @@ class ResourceTestCase(base.BaseTestCase):
         self._test_error_log_level(exc.HTTPInternalServerError,
                                    expect_log_info=False, use_fault_map=False)
 
+    def test_webob_4xx_logged_info_level(self):
+        self._test_error_log_level(exc.HTTPNotFound,
+                                   use_fault_map=False, expect_log_info=True,
+                                   exc_raised=exc.HTTPNotFound)
+
+    def test_webob_5xx_logged_info_level(self):
+        self._test_error_log_level(exc.HTTPServiceUnavailable,
+                                   use_fault_map=False, expect_log_info=False,
+                                   exc_raised=exc.HTTPServiceUnavailable)
+
     def test_no_route_args(self):
         controller = mock.MagicMock()