Attach troubleshooting guide for specific exception types (#665)

* Attach troubleshooting guide for specific exception types

* Fix flake8 on broken test cases

azure_functions_worker/constants.py

@@ -9,3 +9,6 @@
 
 # Feature Flags (app settings)
 PYTHON_ROLLBACK_CWD_PATH = "PYTHON_ROLLBACK_CWD_PATH"
+
+# External Site URLs
+MODULE_NOT_FOUND_TS_URL = "https://aka.ms/functions-modulenotfound"

azure_functions_worker/dispatcher.py

@@ -24,7 +24,7 @@
 
 from .logging import error_logger, logger, is_system_log_category
 from .logging import enable_console_logging, disable_console_logging
-from .tracing import marshall_exception_trace
+from .utils.tracing import marshall_exception_trace
 from .utils.wrappers import disable_feature_by
 
 

azure_functions_worker/loader.py

@@ -10,6 +10,9 @@
 import sys
 import typing
 
+from .constants import MODULE_NOT_FOUND_TS_URL
+from .utils.wrappers import attach_message_to_exception
+
 
 _AZURE_NAMESPACE = '__app__'
 
@@ -33,6 +36,10 @@ def uninstall():
     pass
 
 
+@attach_message_to_exception(
+    expt_type=ImportError,
+    message=f'Troubleshooting Guide: {MODULE_NOT_FOUND_TS_URL}'
+)
 def load_function(name: str, directory: str, script_file: str,
                   entry_point: typing.Optional[str]):
     dir_path = pathlib.Path(directory)

azure_functions_worker/tracing.py → azure_functions_worker/utils/tracing.py

@@ -2,6 +2,17 @@
 import traceback
 
 
+def extend_exception_message(exc: Exception, msg: str) -> Exception:
+    # Reconstruct exception message
+    # From: ImportModule: no module name
+    #   To: ImportModule: no module name. msg
+    old_tb = exc.__traceback__
+    old_msg = getattr(exc, 'msg', None) or str(exc) or ''
+    new_msg = (old_msg.rstrip('.') + '. ' + msg).rstrip()
+    new_excpt = type(exc)(new_msg).with_traceback(old_tb)
+    return new_excpt
+
+
 def marshall_exception_trace(exc: Exception) -> str:
     stack_summary: traceback.StackSummary = traceback.extract_tb(
         exc.__traceback__)

azure_functions_worker/utils/wrappers.py

@@ -1,4 +1,5 @@
 from .common import is_envvar_true
+from .tracing import extend_exception_message
 
 
 def enable_feature_by(flag: str, default=None):
@@ -19,3 +20,14 @@ def call(*args, **kwargs):
             return default
         return call
     return decorate
+
+
+def attach_message_to_exception(expt_type: Exception, message: str):
+    def decorate(func):
+        def call(*args, **kwargs):
+            try:
+                return func(*args, **kwargs)
+            except expt_type as e:
+                raise extend_exception_message(e, message)
+        return call
+    return decorate

tests/unittests/http_functions/missing_module/function.json

@@ -0,0 +1,15 @@
+{
+    "scriptFile": "main.py",
+    "bindings": [
+      {
+        "type": "httpTrigger",
+        "direction": "in",
+        "name": "req"
+      },
+      {
+        "type": "http",
+        "direction": "out",
+        "name": "$return"
+      }
+    ]
+  }

tests/unittests/http_functions/missing_module/main.py

@@ -0,0 +1,12 @@
+import logging
+
+import azure.functions
+import does_not_exist  # Noqa
+
+
+logger = logging.getLogger('my function')
+
+
+def main(req: azure.functions.HttpRequest):
+    logger.info('Function should fail before hitting main')
+    return 'OK-async'

tests/unittests/load_functions/brokenimplicit/function.json

@@ -0,0 +1,16 @@
+{
+    "scriptFile": "main.py",
+    "entryPoint": "customentry",
+    "bindings": [
+      {
+        "type": "httpTrigger",
+        "direction": "in",
+        "name": "req"
+      },
+      {
+        "type": "http",
+        "direction": "out",
+        "name": "$return"
+      }
+    ]
+  }

tests/unittests/load_functions/brokenimplicit/main.py

@@ -0,0 +1,6 @@
+# Import simple module with implicit directory import statement should fail
+from simple.main import main as s_main
+
+
+def brokenimplicit(req) -> str:
+    return f's_main = {s_main(req)}'

tests/unittests/test_http_functions.py

@@ -282,3 +282,13 @@ def test_user_event_loop_error(self):
 
     def check_log_user_event_loop_error(self, host_out: typing.List[str]):
         self.assertIn('try_log', host_out)
+
+    def test_import_module_troubleshooting_url(self):
+        r = self.webhost.request('GET', 'missing_module/')
+        self.assertEqual(r.status_code, 500)
+
+    def check_log_import_module_troubleshooting_url(self, host_out):
+        self.assertIn("Exception: ModuleNotFoundError: "
+                      "No module named 'does_not_exist'. "
+                      "Troubleshooting Guide: "
+                      "https://aka.ms/functions-modulenotfound", host_out)

tests/unittests/test_loader.py

@@ -43,6 +43,16 @@ def test_loader_parentmodule(self):
         self.assertEqual(r.status_code, 200)
         self.assertEqual(r.text, '__app__.parentmodule.module')
 
+    def test_loader_brokenimplicit(self):
+        r = self.webhost.request('GET', 'brokenimplicit')
+        self.assertEqual(r.status_code, 500)
+
+    def check_log_loader_brokenimplicit(self, host_out):
+        self.assertIn("Exception: ModuleNotFoundError: "
+                      "No module named 'simple'. "
+                      "Troubleshooting Guide: "
+                      "https://aka.ms/functions-modulenotfound", host_out)
+
 
 class TestPluginLoader(testutils.AsyncTestCase):
 

tests/unittests/test_utilities.py

@@ -29,6 +29,26 @@ def mock_feature_default(self, output: typing.List[str]) -> str:
         return result
 
 
+class MockMethod:
+    @wrappers.attach_message_to_exception(ImportError, 'success')
+    def mock_load_function_success(self):
+        return True
+
+    @wrappers.attach_message_to_exception(ImportError, 'module_not_found')
+    def mock_load_function_module_not_found(self):
+        raise ModuleNotFoundError('MODULE_NOT_FOUND')
+
+    @wrappers.attach_message_to_exception(ImportError, 'import_error')
+    def mock_load_function_import_error(self):
+        # ImportError is a subclass of ModuleNotFoundError
+        raise ImportError('IMPORT_ERROR')
+
+    @wrappers.attach_message_to_exception(ImportError, 'value_error')
+    def mock_load_function_value_error(self):
+        # ValueError is not a subclass of ImportError
+        raise ValueError('VALUE_ERROR')
+
+
 class TestUtilities(unittest.TestCase):
 
     def setUp(self):
@@ -115,6 +135,32 @@ def test_disable_feature_with_false_flag_return_default_value(self):
         self.assertEqual(result, FEATURE_DEFAULT)
         self.assertListEqual(output, [])
 
+    def test_exception_message_should_not_be_extended_on_success(self):
+        mock_method = MockMethod()
+        result = mock_method.mock_load_function_success()
+        self.assertTrue(result)
+
+    def test_exception_message_should_be_extended_on_subexception(self):
+        mock_method = MockMethod()
+        with self.assertRaises(Exception) as e:
+            mock_method.mock_load_function_module_not_found()
+            self.assertIn('module_not_found', e.msg)
+            self.assertEqual(type(e), ModuleNotFoundError)
+
+    def test_exception_message_should_be_extended_on_exact_exception(self):
+        mock_method = MockMethod()
+        with self.assertRaises(Exception) as e:
+            mock_method.mock_load_function_module_not_found()
+            self.assertIn('import_error', e.msg)
+            self.assertEqual(type(e), ImportError)
+
+    def test_exception_message_should_not_be_extended_on_other_exception(self):
+        mock_method = MockMethod()
+        with self.assertRaises(Exception) as e:
+            mock_method.mock_load_function_value_error()
+            self.assertNotIn('import_error', e.msg)
+            self.assertEqual(type(e), ValueError)
+
     def _unset_feature_flag(self):
         try:
             os.environ.pop(TEST_FEATURE_FLAG)