diff --git a/azure_functions_worker/constants.py b/azure_functions_worker/constants.py index 15e171ff..ff676b11 100644 --- a/azure_functions_worker/constants.py +++ b/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" diff --git a/azure_functions_worker/dispatcher.py b/azure_functions_worker/dispatcher.py index b657b360..eb1c13c4 100644 --- a/azure_functions_worker/dispatcher.py +++ b/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 diff --git a/azure_functions_worker/loader.py b/azure_functions_worker/loader.py index 732babae..271780e8 100644 --- a/azure_functions_worker/loader.py +++ b/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) diff --git a/azure_functions_worker/tracing.py b/azure_functions_worker/utils/tracing.py similarity index 70% rename from azure_functions_worker/tracing.py rename to azure_functions_worker/utils/tracing.py index 200b82fb..32e0e1de 100644 --- a/azure_functions_worker/tracing.py +++ b/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__) diff --git a/azure_functions_worker/utils/wrappers.py b/azure_functions_worker/utils/wrappers.py index 15345c4d..a86105cd 100644 --- a/azure_functions_worker/utils/wrappers.py +++ b/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 diff --git a/tests/unittests/http_functions/missing_module/function.json b/tests/unittests/http_functions/missing_module/function.json new file mode 100644 index 00000000..985453fc --- /dev/null +++ b/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" + } + ] + } diff --git a/tests/unittests/http_functions/missing_module/main.py b/tests/unittests/http_functions/missing_module/main.py new file mode 100644 index 00000000..354f383e --- /dev/null +++ b/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' diff --git a/tests/unittests/load_functions/brokenimplicit/function.json b/tests/unittests/load_functions/brokenimplicit/function.json new file mode 100644 index 00000000..0c705042 --- /dev/null +++ b/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" + } + ] + } diff --git a/tests/unittests/load_functions/brokenimplicit/main.py b/tests/unittests/load_functions/brokenimplicit/main.py new file mode 100644 index 00000000..f587ad18 --- /dev/null +++ b/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)}' diff --git a/tests/unittests/test_http_functions.py b/tests/unittests/test_http_functions.py index 099e704a..81f96121 100644 --- a/tests/unittests/test_http_functions.py +++ b/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) diff --git a/tests/unittests/test_loader.py b/tests/unittests/test_loader.py index db59a59e..fe5dcf3e 100644 --- a/tests/unittests/test_loader.py +++ b/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): diff --git a/tests/unittests/test_utilities.py b/tests/unittests/test_utilities.py index 5b8f0c7b..f2b904db 100644 --- a/tests/unittests/test_utilities.py +++ b/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)