diff --git a/azure_functions_worker/dispatcher.py b/azure_functions_worker/dispatcher.py index f8dd1e8b6..6a4bd8bdf 100644 --- a/azure_functions_worker/dispatcher.py +++ b/azure_functions_worker/dispatcher.py @@ -296,6 +296,10 @@ async def _handle__functions_metadata_request(self, request): directory = metadata_request.function_app_directory function_path = os.path.join(directory, SCRIPT_FILE_NAME) + logger.info( + 'Received WorkerMetadataRequest, request ID %s, directory: %s', + self.request_id, directory) + if not os.path.exists(function_path): # Fallback to legacy model logger.info(f"{SCRIPT_FILE_NAME} does not exist. " @@ -310,13 +314,15 @@ async def _handle__functions_metadata_request(self, request): try: fx_metadata_results = [] indexed_functions = loader.index_function_app(function_path) + logger.info('Indexed function app and found {} functions', + len(indexed_functions)) if indexed_functions: indexed_function_logs: List[str] = [] for func in indexed_functions: - function_log = \ - f"Function Name: {func.get_function_name()} " \ - "Function Binding: " \ - f"{[binding.name for binding in func.get_bindings()]}" + function_log = "Function Name: {}, Function Binding: {}" \ + .format(func.get_function_name(), + [(binding.type, binding.name) for binding in + func.get_bindings()]) indexed_function_logs.append(function_log) logger.info( @@ -327,8 +333,8 @@ async def _handle__functions_metadata_request(self, request): self._functions, indexed_functions) else: - logger.warning("No functions indexed. Please refer to the " - "documentation.") + logger.warning("No functions indexed. Please refer to " + "aka.ms/pythonprogrammingmodel for more info.") return protos.StreamingMessage( request_id=request.request_id, @@ -350,6 +356,10 @@ async def _handle__function_load_request(self, request): function_id = func_request.function_id function_name = func_request.metadata.name + logger.info( + 'Received WorkerLoadRequest, request ID %s, function_id: %s,' + 'function_name: %s,', self.request_id, function_id, function_name) + try: if not self._functions.get_function(function_id): func = loader.load_function( diff --git a/azure_functions_worker/loader.py b/azure_functions_worker/loader.py index a5ec98f36..b3831b4f5 100644 --- a/azure_functions_worker/loader.py +++ b/azure_functions_worker/loader.py @@ -21,6 +21,11 @@ _DEFAULT_SCRIPT_FILENAME = '__init__.py' _DEFAULT_ENTRY_POINT = 'main' +PKGS_PATH = pathlib.Path("site/wwwroot/.python_packages") +home = pathlib.Path.home() +pkgs_path = os.path.join(home, PKGS_PATH) + + _submodule_dirs = [] @@ -88,8 +93,10 @@ def process_indexed_function(functions_registry: functions.Registry, expt_type=ImportError, message=f'Please check the requirements.txt file for the missing module. ' f'For more info, please refer the troubleshooting' - f' guide: {MODULE_NOT_FOUND_TS_URL} ' -) + f' guide: {MODULE_NOT_FOUND_TS_URL} ', + debug_logs='Error in load_function. ' + f'Sys Path: {sys.path}, Sys Module: {sys.modules},' + f'python-packages Path exists: {os.path.exists(pkgs_path)}') def load_function(name: str, directory: str, script_file: str, entry_point: Optional[str]): dir_path = pathlib.Path(directory) @@ -137,8 +144,10 @@ def load_function(name: str, directory: str, script_file: str, @attach_message_to_exception( expt_type=ImportError, - message=f'Troubleshooting Guide: {MODULE_NOT_FOUND_TS_URL}' -) + message=f'Troubleshooting Guide: {MODULE_NOT_FOUND_TS_URL}', + debug_logs='Error in index_function_app. ' + f'Sys Path: {sys.path}, Sys Module: {sys.modules},' + f'python-packages Path exists: {os.path.exists(pkgs_path)}') def index_function_app(function_path: str): module_name = pathlib.Path(function_path).stem imported_module = importlib.import_module(module_name) diff --git a/azure_functions_worker/utils/wrappers.py b/azure_functions_worker/utils/wrappers.py index a1d3af675..2a4afd64c 100644 --- a/azure_functions_worker/utils/wrappers.py +++ b/azure_functions_worker/utils/wrappers.py @@ -1,8 +1,11 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License. + +from typing import Callable, Any + from .common import is_envvar_true, is_envvar_false from .tracing import extend_exception_message -from typing import Callable, Any +from ..logging import logger def enable_feature_by(flag: str, @@ -33,12 +36,15 @@ def call(*args, **kwargs): return decorate -def attach_message_to_exception(expt_type: Exception, message: str) -> Callable: +def attach_message_to_exception(expt_type: Exception, message: str, + debug_logs=None) -> Callable: def decorate(func): def call(*args, **kwargs): try: return func(*args, **kwargs) except expt_type as e: + if debug_logs is not None: + logger.error(debug_logs) raise extend_exception_message(e, message) return call return decorate diff --git a/setup.py b/setup.py index 68eaff86f..4ef8b6703 100644 --- a/setup.py +++ b/setup.py @@ -118,7 +118,7 @@ "azure-eventhub~=5.7.0", # Used for EventHub E2E tests "azure-functions-durable", # Used for Durable E2E tests "flask", - "fastapi", + "fastapi~=0.85.0", # Used for ASGIMiddleware test "pydantic", "pycryptodome~=3.10.1", "flake8~=4.0.1", diff --git a/tests/endtoend/test_sql_functions.py b/tests/endtoend/test_sql_functions.py index ba8c442c4..646ee67b6 100644 --- a/tests/endtoend/test_sql_functions.py +++ b/tests/endtoend/test_sql_functions.py @@ -1,10 +1,12 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License. import json +from unittest import skip from azure_functions_worker import testutils +@skip("Unskip when azure functions with SQL is released.") class TestSqlFunctions(testutils.WebHostTestCase): @classmethod