From e810e0f79a5b4ee2dcd212827edd88d24d102ecb Mon Sep 17 00:00:00 2001 From: hallvictoria Date: Mon, 13 Nov 2023 17:33:01 -0600 Subject: [PATCH 01/12] python specific app setting logs added --- azure_functions_worker/dispatcher.py | 50 +++++++++++++++++++++++++--- 1 file changed, 45 insertions(+), 5 deletions(-) diff --git a/azure_functions_worker/dispatcher.py b/azure_functions_worker/dispatcher.py index 073a04c08..188df029b 100644 --- a/azure_functions_worker/dispatcher.py +++ b/azure_functions_worker/dispatcher.py @@ -21,11 +21,18 @@ from . import bindings, constants, functions, loader, protos from .bindings.shared_memory_data_transfer import SharedMemoryManager -from .constants import (PYTHON_THREADPOOL_THREAD_COUNT, +from .constants import (PYTHON_ROLLBACK_CWD_PATH, + PYTHON_THREADPOOL_THREAD_COUNT, PYTHON_THREADPOOL_THREAD_COUNT_DEFAULT, PYTHON_THREADPOOL_THREAD_COUNT_MAX_37, PYTHON_THREADPOOL_THREAD_COUNT_MIN, - PYTHON_ENABLE_DEBUG_LOGGING, SCRIPT_FILE_NAME, + PYTHON_ISOLATE_WORKER_DEPENDENCIES, + PYTHON_ISOLATE_WORKER_DEPENDENCIES_DEFAULT, + PYTHON_ENABLE_WORKER_EXTENSIONS, + PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT, + PYTHON_ENABLE_DEBUG_LOGGING, + FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED, + SCRIPT_FILE_NAME, PYTHON_LANGUAGE_RUNTIME, CUSTOMER_PACKAGES_PATH) from .extension import ExtensionManager from .logging import disable_console_logging, enable_console_logging @@ -265,11 +272,14 @@ async def _handle__worker_init_request(self, request): 'python version %s, ' 'worker version %s, ' 'request ID %s.' + 'App Settings state: %s.' ' To enable debug level logging, please refer to ' 'https://aka.ms/python-enable-debug-logging', sys.version, VERSION, - self.request_id) + self.request_id, + self.get_python_appsetting_state() + ) worker_init_request = request.worker_init_request host_capabilities = worker_init_request.capabilities @@ -546,9 +556,11 @@ async def _handle__function_environment_reload_request(self, request): try: logger.info('Received FunctionEnvironmentReloadRequest, ' 'request ID: %s,' + 'App Settings state: %s.', ' To enable debug level logging, please refer to ' 'https://aka.ms/python-enable-debug-logging', - self.request_id) + self.request_id, + self.get_python_appsetting_state()) func_env_reload_request = \ request.function_environment_reload_request @@ -689,7 +701,7 @@ def _get_context(invoc_request: protos.InvocationRequest, name: str, name, directory, invoc_request.invocation_id, _invocation_id_local, trace_context, retry_context) - @disable_feature_by(constants.PYTHON_ROLLBACK_CWD_PATH) + @disable_feature_by(PYTHON_ROLLBACK_CWD_PATH) def _change_cwd(self, new_cwd: str): if os.path.exists(new_cwd): os.chdir(new_cwd) @@ -813,6 +825,34 @@ def gen(resp_queue): format_exception(ex))) raise + def get_python_appsetting_state(self): + app_settings = {"PYTHON_ROLLBACK_CWD_PATH": + get_app_setting( + setting=PYTHON_ROLLBACK_CWD_PATH, + default_value='false'), + "PYTHON_THREADPOOL_THREAD_COUNT": + get_app_setting( + setting=PYTHON_THREADPOOL_THREAD_COUNT, + default_value=PYTHON_THREADPOOL_THREAD_COUNT_DEFAULT), + "PYTHON_ISOLATE_WORKER_DEPENDENCIES": + get_app_setting( + setting=PYTHON_ISOLATE_WORKER_DEPENDENCIES, + default_value=PYTHON_ISOLATE_WORKER_DEPENDENCIES_DEFAULT), + "PYTHON_ENABLE_WORKER_EXTENSIONS": + get_app_setting( + setting=PYTHON_ENABLE_WORKER_EXTENSIONS, + default_value=PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT), + "PYTHON_ENABLE_DEBUG_LOGGING": + get_app_setting( + setting=PYTHON_ENABLE_DEBUG_LOGGING, + default_value='false'), + "FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED": + get_app_setting( + setting=FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED, + default_value='false'), + } + + return str(app_settings) class AsyncLoggingHandler(logging.Handler): From 4ec252d319d3c043639ae6df101167ed3a1a39e3 Mon Sep 17 00:00:00 2001 From: hallvictoria Date: Mon, 13 Nov 2023 17:43:33 -0600 Subject: [PATCH 02/12] lint --- azure_functions_worker/dispatcher.py | 26 ++++++++++++++------------ 1 file changed, 14 insertions(+), 12 deletions(-) diff --git a/azure_functions_worker/dispatcher.py b/azure_functions_worker/dispatcher.py index 188df029b..bf66e2530 100644 --- a/azure_functions_worker/dispatcher.py +++ b/azure_functions_worker/dispatcher.py @@ -30,7 +30,7 @@ PYTHON_ISOLATE_WORKER_DEPENDENCIES_DEFAULT, PYTHON_ENABLE_WORKER_EXTENSIONS, PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT, - PYTHON_ENABLE_DEBUG_LOGGING, + PYTHON_ENABLE_DEBUG_LOGGING, FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED, SCRIPT_FILE_NAME, PYTHON_LANGUAGE_RUNTIME, CUSTOMER_PACKAGES_PATH) @@ -826,34 +826,36 @@ def gen(resp_queue): raise def get_python_appsetting_state(self): - app_settings = {"PYTHON_ROLLBACK_CWD_PATH": - get_app_setting( + app_settings = { + "PYTHON_ROLLBACK_CWD_PATH": + get_app_setting( setting=PYTHON_ROLLBACK_CWD_PATH, default_value='false'), - "PYTHON_THREADPOOL_THREAD_COUNT": - get_app_setting( + "PYTHON_THREADPOOL_THREAD_COUNT": + get_app_setting( setting=PYTHON_THREADPOOL_THREAD_COUNT, default_value=PYTHON_THREADPOOL_THREAD_COUNT_DEFAULT), - "PYTHON_ISOLATE_WORKER_DEPENDENCIES": - get_app_setting( + "PYTHON_ISOLATE_WORKER_DEPENDENCIES": + get_app_setting( setting=PYTHON_ISOLATE_WORKER_DEPENDENCIES, default_value=PYTHON_ISOLATE_WORKER_DEPENDENCIES_DEFAULT), - "PYTHON_ENABLE_WORKER_EXTENSIONS": - get_app_setting( + "PYTHON_ENABLE_WORKER_EXTENSIONS": + get_app_setting( setting=PYTHON_ENABLE_WORKER_EXTENSIONS, default_value=PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT), "PYTHON_ENABLE_DEBUG_LOGGING": - get_app_setting( + get_app_setting( setting=PYTHON_ENABLE_DEBUG_LOGGING, default_value='false'), - "FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED": - get_app_setting( + "FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED": + get_app_setting( setting=FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED, default_value='false'), } return str(app_settings) + class AsyncLoggingHandler(logging.Handler): def emit(self, record: LogRecord) -> None: From a7045ad83a003108616bdbd0cd1d2d6940eabe47 Mon Sep 17 00:00:00 2001 From: hallvictoria Date: Mon, 13 Nov 2023 22:04:12 -0600 Subject: [PATCH 03/12] refactor --- azure_functions_worker/constants.py | 41 +++++++++++++++++++++++++++ azure_functions_worker/dispatcher.py | 42 +++------------------------- 2 files changed, 45 insertions(+), 38 deletions(-) diff --git a/azure_functions_worker/constants.py b/azure_functions_worker/constants.py index 523f36364..0c2c69558 100644 --- a/azure_functions_worker/constants.py +++ b/azure_functions_worker/constants.py @@ -1,5 +1,6 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License. +import os import sys # Capabilities @@ -30,6 +31,7 @@ UNIX_SHARED_MEMORY_DIRECTORIES = "FUNCTIONS_UNIX_SHARED_MEMORY_DIRECTORIES" # Setting Defaults +PYTHON_ROLLBACK_CWD_PATH_DEFAULT = False PYTHON_THREADPOOL_THREAD_COUNT_DEFAULT = 1 PYTHON_THREADPOOL_THREAD_COUNT_MIN = 1 PYTHON_THREADPOOL_THREAD_COUNT_MAX = sys.maxsize @@ -39,6 +41,8 @@ PYTHON_ISOLATE_WORKER_DEPENDENCIES_DEFAULT_310 = False PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT = False PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT_39 = True +PYTHON_ENABLE_DEBUG_LOGGING_DEFAULT = False +FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED_DEFAULT = False PYTHON_EXTENSIONS_RELOAD_FUNCTIONS = "PYTHON_EXTENSIONS_RELOAD_FUNCTIONS" # External Site URLs @@ -53,3 +57,40 @@ # Paths CUSTOMER_PACKAGES_PATH = "/home/site/wwwroot/.python_packages/lib/site-packages" + + +def get_python_appsetting_state(): + app_settings = { + "PYTHON_ROLLBACK_CWD_PATH": + get_statement(PYTHON_ROLLBACK_CWD_PATH, + PYTHON_ROLLBACK_CWD_PATH_DEFAULT), + "PYTHON_THREADPOOL_THREAD_COUNT": + get_statement(PYTHON_THREADPOOL_THREAD_COUNT, + PYTHON_THREADPOOL_THREAD_COUNT_DEFAULT), + "PYTHON_ISOLATE_WORKER_DEPENDENCIES": + get_statement(PYTHON_ISOLATE_WORKER_DEPENDENCIES, + PYTHON_ISOLATE_WORKER_DEPENDENCIES_DEFAULT), + "PYTHON_ENABLE_WORKER_EXTENSIONS": + get_statement(PYTHON_ENABLE_WORKER_EXTENSIONS, + PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT), + "PYTHON_ENABLE_DEBUG_LOGGING": + get_statement(PYTHON_ENABLE_DEBUG_LOGGING, + PYTHON_ENABLE_DEBUG_LOGGING_DEFAULT), + "FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED": + get_statement(FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED, + "False") + } + + return str(app_settings) + + +def get_statement(app_setting, default_value): + app_setting_state = os.getenv(app_setting) + + if app_setting_state is None: + app_setting_state = str(default_value) + + if app_setting in os.environ: + return "set to " + app_setting_state + " by customer" + else: + return "set to " + app_setting_state + " by default" diff --git a/azure_functions_worker/dispatcher.py b/azure_functions_worker/dispatcher.py index bf66e2530..99a832be9 100644 --- a/azure_functions_worker/dispatcher.py +++ b/azure_functions_worker/dispatcher.py @@ -26,14 +26,10 @@ PYTHON_THREADPOOL_THREAD_COUNT_DEFAULT, PYTHON_THREADPOOL_THREAD_COUNT_MAX_37, PYTHON_THREADPOOL_THREAD_COUNT_MIN, - PYTHON_ISOLATE_WORKER_DEPENDENCIES, - PYTHON_ISOLATE_WORKER_DEPENDENCIES_DEFAULT, - PYTHON_ENABLE_WORKER_EXTENSIONS, - PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT, PYTHON_ENABLE_DEBUG_LOGGING, - FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED, SCRIPT_FILE_NAME, - PYTHON_LANGUAGE_RUNTIME, CUSTOMER_PACKAGES_PATH) + PYTHON_LANGUAGE_RUNTIME, CUSTOMER_PACKAGES_PATH, + get_python_appsetting_state) from .extension import ExtensionManager from .logging import disable_console_logging, enable_console_logging from .logging import (logger, error_logger, is_system_log_category, @@ -278,7 +274,7 @@ async def _handle__worker_init_request(self, request): sys.version, VERSION, self.request_id, - self.get_python_appsetting_state() + get_python_appsetting_state() ) worker_init_request = request.worker_init_request @@ -560,7 +556,7 @@ async def _handle__function_environment_reload_request(self, request): ' To enable debug level logging, please refer to ' 'https://aka.ms/python-enable-debug-logging', self.request_id, - self.get_python_appsetting_state()) + get_python_appsetting_state()) func_env_reload_request = \ request.function_environment_reload_request @@ -825,36 +821,6 @@ def gen(resp_queue): format_exception(ex))) raise - def get_python_appsetting_state(self): - app_settings = { - "PYTHON_ROLLBACK_CWD_PATH": - get_app_setting( - setting=PYTHON_ROLLBACK_CWD_PATH, - default_value='false'), - "PYTHON_THREADPOOL_THREAD_COUNT": - get_app_setting( - setting=PYTHON_THREADPOOL_THREAD_COUNT, - default_value=PYTHON_THREADPOOL_THREAD_COUNT_DEFAULT), - "PYTHON_ISOLATE_WORKER_DEPENDENCIES": - get_app_setting( - setting=PYTHON_ISOLATE_WORKER_DEPENDENCIES, - default_value=PYTHON_ISOLATE_WORKER_DEPENDENCIES_DEFAULT), - "PYTHON_ENABLE_WORKER_EXTENSIONS": - get_app_setting( - setting=PYTHON_ENABLE_WORKER_EXTENSIONS, - default_value=PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT), - "PYTHON_ENABLE_DEBUG_LOGGING": - get_app_setting( - setting=PYTHON_ENABLE_DEBUG_LOGGING, - default_value='false'), - "FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED": - get_app_setting( - setting=FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED, - default_value='false'), - } - - return str(app_settings) - class AsyncLoggingHandler(logging.Handler): From 59b950bf6e3a8ffb1682d01dd3f1a5687e919331 Mon Sep 17 00:00:00 2001 From: hallvictoria Date: Tue, 14 Nov 2023 09:18:10 -0600 Subject: [PATCH 04/12] codeowner --- CODEOWNERS | 2 +- azure_functions_worker/constants.py | 9 +++------ 2 files changed, 4 insertions(+), 7 deletions(-) diff --git a/CODEOWNERS b/CODEOWNERS index 05f323788..f93501102 100644 --- a/CODEOWNERS +++ b/CODEOWNERS @@ -10,4 +10,4 @@ # For all file changes, github would automatically # include the following people in the PRs. -* @vrdmr @gavin-aguiar @YunchuWang @pdthummar +* @vrdmr @gavin-aguiar @YunchuWang @pdthummar @hallvictoria diff --git a/azure_functions_worker/constants.py b/azure_functions_worker/constants.py index 0c2c69558..51742d8b2 100644 --- a/azure_functions_worker/constants.py +++ b/azure_functions_worker/constants.py @@ -31,7 +31,6 @@ UNIX_SHARED_MEMORY_DIRECTORIES = "FUNCTIONS_UNIX_SHARED_MEMORY_DIRECTORIES" # Setting Defaults -PYTHON_ROLLBACK_CWD_PATH_DEFAULT = False PYTHON_THREADPOOL_THREAD_COUNT_DEFAULT = 1 PYTHON_THREADPOOL_THREAD_COUNT_MIN = 1 PYTHON_THREADPOOL_THREAD_COUNT_MAX = sys.maxsize @@ -41,8 +40,6 @@ PYTHON_ISOLATE_WORKER_DEPENDENCIES_DEFAULT_310 = False PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT = False PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT_39 = True -PYTHON_ENABLE_DEBUG_LOGGING_DEFAULT = False -FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED_DEFAULT = False PYTHON_EXTENSIONS_RELOAD_FUNCTIONS = "PYTHON_EXTENSIONS_RELOAD_FUNCTIONS" # External Site URLs @@ -63,7 +60,7 @@ def get_python_appsetting_state(): app_settings = { "PYTHON_ROLLBACK_CWD_PATH": get_statement(PYTHON_ROLLBACK_CWD_PATH, - PYTHON_ROLLBACK_CWD_PATH_DEFAULT), + ""), "PYTHON_THREADPOOL_THREAD_COUNT": get_statement(PYTHON_THREADPOOL_THREAD_COUNT, PYTHON_THREADPOOL_THREAD_COUNT_DEFAULT), @@ -75,10 +72,10 @@ def get_python_appsetting_state(): PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT), "PYTHON_ENABLE_DEBUG_LOGGING": get_statement(PYTHON_ENABLE_DEBUG_LOGGING, - PYTHON_ENABLE_DEBUG_LOGGING_DEFAULT), + "0"), "FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED": get_statement(FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED, - "False") + "0") } return str(app_settings) From 6cefbb71458a9bb7c853193bbdcfe6c04833e1cc Mon Sep 17 00:00:00 2001 From: hallvictoria Date: Tue, 14 Nov 2023 09:27:29 -0600 Subject: [PATCH 05/12] manual convert dict to string --- azure_functions_worker/constants.py | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/azure_functions_worker/constants.py b/azure_functions_worker/constants.py index 51742d8b2..8c807ecb0 100644 --- a/azure_functions_worker/constants.py +++ b/azure_functions_worker/constants.py @@ -78,7 +78,12 @@ def get_python_appsetting_state(): "0") } - return str(app_settings) + # convert to string + app_settings_string = "" + for item in app_settings: + app_settings_string += item + ": " + app_settings[item] + " " + + return app_settings_string def get_statement(app_setting, default_value): From f69616f6092997331044985411d3441efb63e18a Mon Sep 17 00:00:00 2001 From: hallvictoria Date: Tue, 14 Nov 2023 11:24:47 -0600 Subject: [PATCH 06/12] moved to utils, more efficient --- azure_functions_worker/constants.py | 43 ------------------- azure_functions_worker/dispatcher.py | 4 +- .../utils/app_settings_logs.py | 34 +++++++++++++++ 3 files changed, 36 insertions(+), 45 deletions(-) create mode 100644 azure_functions_worker/utils/app_settings_logs.py diff --git a/azure_functions_worker/constants.py b/azure_functions_worker/constants.py index 8c807ecb0..523f36364 100644 --- a/azure_functions_worker/constants.py +++ b/azure_functions_worker/constants.py @@ -1,6 +1,5 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License. -import os import sys # Capabilities @@ -54,45 +53,3 @@ # Paths CUSTOMER_PACKAGES_PATH = "/home/site/wwwroot/.python_packages/lib/site-packages" - - -def get_python_appsetting_state(): - app_settings = { - "PYTHON_ROLLBACK_CWD_PATH": - get_statement(PYTHON_ROLLBACK_CWD_PATH, - ""), - "PYTHON_THREADPOOL_THREAD_COUNT": - get_statement(PYTHON_THREADPOOL_THREAD_COUNT, - PYTHON_THREADPOOL_THREAD_COUNT_DEFAULT), - "PYTHON_ISOLATE_WORKER_DEPENDENCIES": - get_statement(PYTHON_ISOLATE_WORKER_DEPENDENCIES, - PYTHON_ISOLATE_WORKER_DEPENDENCIES_DEFAULT), - "PYTHON_ENABLE_WORKER_EXTENSIONS": - get_statement(PYTHON_ENABLE_WORKER_EXTENSIONS, - PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT), - "PYTHON_ENABLE_DEBUG_LOGGING": - get_statement(PYTHON_ENABLE_DEBUG_LOGGING, - "0"), - "FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED": - get_statement(FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED, - "0") - } - - # convert to string - app_settings_string = "" - for item in app_settings: - app_settings_string += item + ": " + app_settings[item] + " " - - return app_settings_string - - -def get_statement(app_setting, default_value): - app_setting_state = os.getenv(app_setting) - - if app_setting_state is None: - app_setting_state = str(default_value) - - if app_setting in os.environ: - return "set to " + app_setting_state + " by customer" - else: - return "set to " + app_setting_state + " by default" diff --git a/azure_functions_worker/dispatcher.py b/azure_functions_worker/dispatcher.py index 99a832be9..2855cbaf9 100644 --- a/azure_functions_worker/dispatcher.py +++ b/azure_functions_worker/dispatcher.py @@ -28,12 +28,12 @@ PYTHON_THREADPOOL_THREAD_COUNT_MIN, PYTHON_ENABLE_DEBUG_LOGGING, SCRIPT_FILE_NAME, - PYTHON_LANGUAGE_RUNTIME, CUSTOMER_PACKAGES_PATH, - get_python_appsetting_state) + PYTHON_LANGUAGE_RUNTIME, CUSTOMER_PACKAGES_PATH) from .extension import ExtensionManager from .logging import disable_console_logging, enable_console_logging from .logging import (logger, error_logger, is_system_log_category, CONSOLE_LOG_PREFIX, format_exception) +from .utils.app_settings_logs import get_python_appsetting_state from .utils.common import get_app_setting, is_envvar_true from .utils.dependency import DependencyManager from .utils.tracing import marshall_exception_trace diff --git a/azure_functions_worker/utils/app_settings_logs.py b/azure_functions_worker/utils/app_settings_logs.py new file mode 100644 index 000000000..2cb009073 --- /dev/null +++ b/azure_functions_worker/utils/app_settings_logs.py @@ -0,0 +1,34 @@ +import os + +from ..constants import (PYTHON_ROLLBACK_CWD_PATH, + PYTHON_THREADPOOL_THREAD_COUNT, + PYTHON_ISOLATE_WORKER_DEPENDENCIES, + PYTHON_ENABLE_WORKER_EXTENSIONS, + PYTHON_ENABLE_DEBUG_LOGGING, + FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED) + + +def get_python_appsetting_state(): + current_vars = os.environ.copy() + python_specific_settings = \ + [PYTHON_ROLLBACK_CWD_PATH, + PYTHON_THREADPOOL_THREAD_COUNT, + PYTHON_ISOLATE_WORKER_DEPENDENCIES, + PYTHON_ENABLE_DEBUG_LOGGING, + FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED] + + app_setting_states = "" + + for app_setting in python_specific_settings: + if app_setting in current_vars: + app_setting_states += (app_setting + ": " + + current_vars[app_setting] + " ") + + # Special case for extensions + python_version = current_vars['FUNCTIONS_WORKER_RUNTIME_VERSION'] + if python_version == '3.9': + app_setting_states += PYTHON_ENABLE_WORKER_EXTENSIONS + ": True " + else: + app_setting_states += PYTHON_ENABLE_WORKER_EXTENSIONS + ": False " + + return app_setting_states From 768d5098bdf06d3f37952b2b2055ef7d8c767d2d Mon Sep 17 00:00:00 2001 From: hallvictoria Date: Tue, 14 Nov 2023 12:07:07 -0600 Subject: [PATCH 07/12] added to old tests, created new --- tests/unittests/test_app_settings_logs.py | 102 ++++++++++++++++++++++ tests/unittests/test_dispatcher.py | 30 +++++++ 2 files changed, 132 insertions(+) create mode 100644 tests/unittests/test_app_settings_logs.py diff --git a/tests/unittests/test_app_settings_logs.py b/tests/unittests/test_app_settings_logs.py new file mode 100644 index 000000000..55431eaa4 --- /dev/null +++ b/tests/unittests/test_app_settings_logs.py @@ -0,0 +1,102 @@ +# Copyright (c) Microsoft Corporation. All rights reserved. +# Licensed under the MIT License. +import collections as col +import os + +from unittest.mock import patch + +from tests.utils import testutils +from azure_functions_worker.constants import PYTHON_THREADPOOL_THREAD_COUNT, \ + PYTHON_ENABLE_DEBUG_LOGGING + +SysVersionInfo = col.namedtuple("VersionInfo", ["major", "minor", "micro", + "releaselevel", "serial"]) +DISPATCHER_FUNCTIONS_DIR = testutils.UNIT_TESTS_FOLDER / 'dispatcher_functions' +DISPATCHER_STEIN_FUNCTIONS_DIR = testutils.UNIT_TESTS_FOLDER / \ + 'dispatcher_functions' / \ + 'dispatcher_functions_stein' +DISPATCHER_STEIN_INVALID_FUNCTIONS_DIR = testutils.UNIT_TESTS_FOLDER / \ + 'broken_functions' / \ + 'invalid_stein' + + +class TestDefaultAppSettingsLogs(testutils.AsyncTestCase): + """Tests for default app settings logs.""" + + @classmethod + def setUpClass(self): + self._ctrl = testutils.start_mockhost( + script_root=DISPATCHER_FUNCTIONS_DIR) + os_environ = os.environ.copy() + self._patch_environ = patch.dict('os.environ', os_environ) + self._patch_environ.start() + super().setUpClass() + + def tearDownClass(self): + os.environ.clear() + os.environ.update(self._pre_env) + self.mock_version_info.stop() + + async def test_initialize_worker_logging(self): + """Test if the dispatcher's log can be flushed out during worker + initialization + """ + async with self._ctrl as host: + r = await host.init_worker('3.0.12345') + self.assertEqual( + len([log for log in r.logs if log.message.contains( + 'App Settings state:' + )]), 1 + ) + self.assertEqual( + len([log for log in r.logs if log.message.contains( + 'PYTHON_ENABLE_WORKER_EXTENSIONS:' + )]), 1 + ) + self.assertEqual( + len([log for log in r.logs if log.message.contains( + 'PYTHON_ENABLE_DEBUG_LOGGING:' + )]), 0 + ) + + +class TestNonDefaultAppSettingsLogs(testutils.AsyncTestCase): + """Tests for non-default app settings logs.""" + + @classmethod + def setUpClass(self): + self._ctrl = testutils.start_mockhost( + script_root=DISPATCHER_FUNCTIONS_DIR) + os_environ = os.environ.copy() + os_environ[PYTHON_THREADPOOL_THREAD_COUNT] = '20' + os_environ[PYTHON_ENABLE_DEBUG_LOGGING] = '1' + self._patch_environ = patch.dict('os.environ', os_environ) + self._patch_environ.start() + super().setUpClass() + + def tearDownClass(self): + os.environ.clear() + os.environ.update(self._pre_env) + self.mock_version_info.stop() + + async def test_initialize_worker_logging(self): + """Test if the dispatcher's log can be flushed out during worker + initialization + """ + async with self._ctrl as host: + r = await host.init_worker('3.0.12345') + self.assertEqual( + len([log for log in r.logs if log.message.contains( + 'App Settings state:' + )]), 1 + ) + self.assertEqual( + len([log for log in r.logs if log.message.contains( + 'PYTHON_THREADPOOL_THREAD_COUNT:' + )]), 1 + ) + self.assertEqual( + len([log for log in r.logs if log.message.contains( + 'PYTHON_ENABLE_DEBUG_LOGGING:' + )]), 1 + ) diff --git a/tests/unittests/test_dispatcher.py b/tests/unittests/test_dispatcher.py index eac056e12..ed587ea1b 100644 --- a/tests/unittests/test_dispatcher.py +++ b/tests/unittests/test_dispatcher.py @@ -98,6 +98,19 @@ async def test_dispatcher_initialize_worker_logging(self): 1 ) + async def test_dispatcher_initialize_worker_settings_logs(self): + """Test if the dispatcher's log can be flushed out during worker + initialization + """ + async with self._ctrl as host: + r = await host.init_worker('3.0.12345') + self.assertEqual( + len([log for log in r.logs if log.message.contains( + 'PYTHON_ENABLE_WORKER_EXTENSIONS:' + )]), + 1 + ) + async def test_dispatcher_environment_reload_logging(self): """Test if the sync threadpool will pick up app setting in placeholder mode (Linux Consumption) @@ -115,6 +128,23 @@ async def test_dispatcher_environment_reload_logging(self): 1 ) + async def test_dispatcher_environment_reload_settings_logs(self): + """Test if the sync threadpool will pick up app setting in placeholder + mode (Linux Consumption) + """ + async with self._ctrl as host: + await host.init_worker() + await self._check_if_function_is_ok(host) + + # Reload environment variable on specialization + r = await host.reload_environment(environment={}) + self.assertEqual( + len([log for log in r.logs if log.message.contains( + 'PYTHON_ENABLE_WORKER_EXTENSIONS:' + )]), + 1 + ) + async def test_dispatcher_send_worker_request(self): """Test if the worker status response will be sent correctly when a worker status request is received From bafb83203abaeace451ae7f3377a29de458c896d Mon Sep 17 00:00:00 2001 From: hallvictoria Date: Tue, 14 Nov 2023 13:12:09 -0600 Subject: [PATCH 08/12] addressing comments --- azure_functions_worker/dispatcher.py | 2 +- ...{app_settings_logs.py => app_setting_manager.py} | 12 ++++++++++-- ...settings_logs.py => test_app_setting_manager.py} | 13 +++++++++++++ 3 files changed, 24 insertions(+), 3 deletions(-) rename azure_functions_worker/utils/{app_settings_logs.py => app_setting_manager.py} (64%) rename tests/unittests/{test_app_settings_logs.py => test_app_setting_manager.py} (85%) diff --git a/azure_functions_worker/dispatcher.py b/azure_functions_worker/dispatcher.py index 2855cbaf9..8a90c4877 100644 --- a/azure_functions_worker/dispatcher.py +++ b/azure_functions_worker/dispatcher.py @@ -33,7 +33,7 @@ from .logging import disable_console_logging, enable_console_logging from .logging import (logger, error_logger, is_system_log_category, CONSOLE_LOG_PREFIX, format_exception) -from .utils.app_settings_logs import get_python_appsetting_state +from .utils.app_setting_manager import get_python_appsetting_state from .utils.common import get_app_setting, is_envvar_true from .utils.dependency import DependencyManager from .utils.tracing import marshall_exception_trace diff --git a/azure_functions_worker/utils/app_settings_logs.py b/azure_functions_worker/utils/app_setting_manager.py similarity index 64% rename from azure_functions_worker/utils/app_settings_logs.py rename to azure_functions_worker/utils/app_setting_manager.py index 2cb009073..a461e5ec0 100644 --- a/azure_functions_worker/utils/app_settings_logs.py +++ b/azure_functions_worker/utils/app_setting_manager.py @@ -1,9 +1,13 @@ +# Copyright (c) Microsoft Corporation. All rights reserved. +# Licensed under the MIT License. import os from ..constants import (PYTHON_ROLLBACK_CWD_PATH, PYTHON_THREADPOOL_THREAD_COUNT, PYTHON_ISOLATE_WORKER_DEPENDENCIES, PYTHON_ENABLE_WORKER_EXTENSIONS, + PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT, + PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT_39, PYTHON_ENABLE_DEBUG_LOGGING, FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED) @@ -27,8 +31,12 @@ def get_python_appsetting_state(): # Special case for extensions python_version = current_vars['FUNCTIONS_WORKER_RUNTIME_VERSION'] if python_version == '3.9': - app_setting_states += PYTHON_ENABLE_WORKER_EXTENSIONS + ": True " + app_setting_states += (PYTHON_ENABLE_WORKER_EXTENSIONS + ": " + + str(PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT_39) + + " ") else: - app_setting_states += PYTHON_ENABLE_WORKER_EXTENSIONS + ": False " + app_setting_states += (PYTHON_ENABLE_WORKER_EXTENSIONS + ": " + + str(PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT) + + " ") return app_setting_states diff --git a/tests/unittests/test_app_settings_logs.py b/tests/unittests/test_app_setting_manager.py similarity index 85% rename from tests/unittests/test_app_settings_logs.py rename to tests/unittests/test_app_setting_manager.py index 55431eaa4..2447e2bd8 100644 --- a/tests/unittests/test_app_settings_logs.py +++ b/tests/unittests/test_app_setting_manager.py @@ -6,6 +6,8 @@ from unittest.mock import patch from tests.utils import testutils +from azure_functions_worker.utils.app_setting_manager import \ + get_python_appsetting_state from azure_functions_worker.constants import PYTHON_THREADPOOL_THREAD_COUNT, \ PYTHON_ENABLE_DEBUG_LOGGING @@ -59,6 +61,11 @@ async def test_initialize_worker_logging(self): )]), 0 ) + def test_get_python_appsetting_state(self): + app_setting_state = get_python_appsetting_state() + expected_string = "PYTHON_ENABLE_WORKER_EXTENSIONS: " + self.assertEqual(app_setting_state, expected_string) + class TestNonDefaultAppSettingsLogs(testutils.AsyncTestCase): """Tests for non-default app settings logs.""" @@ -100,3 +107,9 @@ async def test_initialize_worker_logging(self): 'PYTHON_ENABLE_DEBUG_LOGGING:' )]), 1 ) + + def test_get_python_appsetting_state(self): + app_setting_state = get_python_appsetting_state() + expected_string = "PYTHON_THREADPOOL_THREAD_COUNT: 20 PYTHON_ENABLE_DEBUG_LOGGING: \ + 1 PYTHON_ENABLE_WORKER_EXTENSIONS: " + self.assertEqual(app_setting_state, expected_string) From ba11aa81166821de4169d0795394921bc0e4f103 Mon Sep 17 00:00:00 2001 From: hallvictoria Date: Tue, 14 Nov 2023 14:18:01 -0600 Subject: [PATCH 09/12] fixing tests, efficiency --- azure_functions_worker/dispatcher.py | 2 +- .../utils/app_setting_manager.py | 30 +++---- tests/unittests/test_app_setting_manager.py | 79 +++++++------------ tests/unittests/test_dispatcher.py | 16 +--- 4 files changed, 49 insertions(+), 78 deletions(-) diff --git a/azure_functions_worker/dispatcher.py b/azure_functions_worker/dispatcher.py index 8a90c4877..c54270caa 100644 --- a/azure_functions_worker/dispatcher.py +++ b/azure_functions_worker/dispatcher.py @@ -556,7 +556,7 @@ async def _handle__function_environment_reload_request(self, request): ' To enable debug level logging, please refer to ' 'https://aka.ms/python-enable-debug-logging', self.request_id, - get_python_appsetting_state()) + "test") func_env_reload_request = \ request.function_environment_reload_request diff --git a/azure_functions_worker/utils/app_setting_manager.py b/azure_functions_worker/utils/app_setting_manager.py index a461e5ec0..b50719127 100644 --- a/azure_functions_worker/utils/app_setting_manager.py +++ b/azure_functions_worker/utils/app_setting_manager.py @@ -1,6 +1,7 @@ # Copyright (c) Microsoft Corporation. All rights reserved. # Licensed under the MIT License. import os +import sys from ..constants import (PYTHON_ROLLBACK_CWD_PATH, PYTHON_THREADPOOL_THREAD_COUNT, @@ -21,22 +22,21 @@ def get_python_appsetting_state(): PYTHON_ENABLE_DEBUG_LOGGING, FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED] - app_setting_states = "" - - for app_setting in python_specific_settings: - if app_setting in current_vars: - app_setting_states += (app_setting + ": " - + current_vars[app_setting] + " ") + app_setting_states = "".join( + f"{app_setting}: {current_vars[app_setting]} " + for app_setting in python_specific_settings + if app_setting in current_vars + ) # Special case for extensions - python_version = current_vars['FUNCTIONS_WORKER_RUNTIME_VERSION'] - if python_version == '3.9': - app_setting_states += (PYTHON_ENABLE_WORKER_EXTENSIONS + ": " - + str(PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT_39) - + " ") - else: - app_setting_states += (PYTHON_ENABLE_WORKER_EXTENSIONS + ": " - + str(PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT) - + " ") + if 'PYTHON_ENABLE_WORKER_EXTENSIONS' not in current_vars: + if sys.version_info.minor == 9: + app_setting_states += \ + (f"{PYTHON_ENABLE_WORKER_EXTENSIONS}: " + f"{str(PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT_39)}") + else: + app_setting_states += \ + (f"{PYTHON_ENABLE_WORKER_EXTENSIONS}: " + f"{str(PYTHON_ENABLE_WORKER_EXTENSIONS_DEFAULT)} ") return app_setting_states diff --git a/tests/unittests/test_app_setting_manager.py b/tests/unittests/test_app_setting_manager.py index 2447e2bd8..815727fb6 100644 --- a/tests/unittests/test_app_setting_manager.py +++ b/tests/unittests/test_app_setting_manager.py @@ -26,18 +26,18 @@ class TestDefaultAppSettingsLogs(testutils.AsyncTestCase): """Tests for default app settings logs.""" @classmethod - def setUpClass(self): - self._ctrl = testutils.start_mockhost( + def setUpClass(cls): + cls._ctrl = testutils.start_mockhost( script_root=DISPATCHER_FUNCTIONS_DIR) os_environ = os.environ.copy() - self._patch_environ = patch.dict('os.environ', os_environ) - self._patch_environ.start() + cls._patch_environ = patch.dict('os.environ', os_environ) + cls._patch_environ.start() super().setUpClass() - def tearDownClass(self): - os.environ.clear() - os.environ.update(self._pre_env) - self.mock_version_info.stop() + @classmethod + def tearDownClass(cls): + super().tearDownClass() + cls._patch_environ.stop() async def test_initialize_worker_logging(self): """Test if the dispatcher's log can be flushed out during worker @@ -45,46 +45,34 @@ async def test_initialize_worker_logging(self): """ async with self._ctrl as host: r = await host.init_worker('3.0.12345') - self.assertEqual( - len([log for log in r.logs if log.message.contains( - 'App Settings state:' - )]), 1 - ) - self.assertEqual( - len([log for log in r.logs if log.message.contains( - 'PYTHON_ENABLE_WORKER_EXTENSIONS:' - )]), 1 - ) - self.assertEqual( - len([log for log in r.logs if log.message.contains( - 'PYTHON_ENABLE_DEBUG_LOGGING:' - )]), 0 - ) + self.assertTrue('App Settings state: ' in log for log in r.logs) + self.assertTrue('PYTHON_ENABLE_WORKER_EXTENSIONS: ' + in log for log in r.logs) def test_get_python_appsetting_state(self): app_setting_state = get_python_appsetting_state() expected_string = "PYTHON_ENABLE_WORKER_EXTENSIONS: " - self.assertEqual(app_setting_state, expected_string) + self.assertIn(expected_string, app_setting_state) class TestNonDefaultAppSettingsLogs(testutils.AsyncTestCase): """Tests for non-default app settings logs.""" @classmethod - def setUpClass(self): - self._ctrl = testutils.start_mockhost( + def setUpClass(cls): + cls._ctrl = testutils.start_mockhost( script_root=DISPATCHER_FUNCTIONS_DIR) os_environ = os.environ.copy() os_environ[PYTHON_THREADPOOL_THREAD_COUNT] = '20' os_environ[PYTHON_ENABLE_DEBUG_LOGGING] = '1' - self._patch_environ = patch.dict('os.environ', os_environ) - self._patch_environ.start() + cls._patch_environ = patch.dict('os.environ', os_environ) + cls._patch_environ.start() super().setUpClass() - def tearDownClass(self): - os.environ.clear() - os.environ.update(self._pre_env) - self.mock_version_info.stop() + @classmethod + def tearDownClass(cls): + super().tearDownClass() + cls._patch_environ.stop() async def test_initialize_worker_logging(self): """Test if the dispatcher's log can be flushed out during worker @@ -92,24 +80,15 @@ async def test_initialize_worker_logging(self): """ async with self._ctrl as host: r = await host.init_worker('3.0.12345') - self.assertEqual( - len([log for log in r.logs if log.message.contains( - 'App Settings state:' - )]), 1 - ) - self.assertEqual( - len([log for log in r.logs if log.message.contains( - 'PYTHON_THREADPOOL_THREAD_COUNT:' - )]), 1 - ) - self.assertEqual( - len([log for log in r.logs if log.message.contains( - 'PYTHON_ENABLE_DEBUG_LOGGING:' - )]), 1 - ) + self.assertTrue('App Settings state: ' in log for log in r.logs) + self.assertTrue('PYTHON_THREADPOOL_THREAD_COUNT: ' + in log for log in r.logs) + self.assertTrue('PYTHON_ENABLE_DEBUG_LOGGING: ' + in log for log in r.logs) def test_get_python_appsetting_state(self): app_setting_state = get_python_appsetting_state() - expected_string = "PYTHON_THREADPOOL_THREAD_COUNT: 20 PYTHON_ENABLE_DEBUG_LOGGING: \ - 1 PYTHON_ENABLE_WORKER_EXTENSIONS: " - self.assertEqual(app_setting_state, expected_string) + expected_string = ("PYTHON_THREADPOOL_THREAD_COUNT: 20 " + "PYTHON_ENABLE_DEBUG_LOGGING: 1 " + "PYTHON_ENABLE_WORKER_EXTENSIONS: ") + self.assertIn(expected_string, app_setting_state) diff --git a/tests/unittests/test_dispatcher.py b/tests/unittests/test_dispatcher.py index ed587ea1b..43df88193 100644 --- a/tests/unittests/test_dispatcher.py +++ b/tests/unittests/test_dispatcher.py @@ -104,12 +104,8 @@ async def test_dispatcher_initialize_worker_settings_logs(self): """ async with self._ctrl as host: r = await host.init_worker('3.0.12345') - self.assertEqual( - len([log for log in r.logs if log.message.contains( - 'PYTHON_ENABLE_WORKER_EXTENSIONS:' - )]), - 1 - ) + self.assertTrue('PYTHON_ENABLE_WORKER_EXTENSIONS: ' + in log for log in r.logs) async def test_dispatcher_environment_reload_logging(self): """Test if the sync threadpool will pick up app setting in placeholder @@ -138,12 +134,8 @@ async def test_dispatcher_environment_reload_settings_logs(self): # Reload environment variable on specialization r = await host.reload_environment(environment={}) - self.assertEqual( - len([log for log in r.logs if log.message.contains( - 'PYTHON_ENABLE_WORKER_EXTENSIONS:' - )]), - 1 - ) + self.assertTrue('PYTHON_ENABLE_WORKER_EXTENSIONS: ' + in log for log in r.logs) async def test_dispatcher_send_worker_request(self): """Test if the worker status response will be sent correctly when From e894d9c771dfa60d3e27eaf932cbb9c21d260b7f Mon Sep 17 00:00:00 2001 From: hallvictoria Date: Tue, 14 Nov 2023 14:21:59 -0600 Subject: [PATCH 10/12] python worker ext --- azure_functions_worker/utils/app_setting_manager.py | 1 + 1 file changed, 1 insertion(+) diff --git a/azure_functions_worker/utils/app_setting_manager.py b/azure_functions_worker/utils/app_setting_manager.py index b50719127..00394f7d6 100644 --- a/azure_functions_worker/utils/app_setting_manager.py +++ b/azure_functions_worker/utils/app_setting_manager.py @@ -20,6 +20,7 @@ def get_python_appsetting_state(): PYTHON_THREADPOOL_THREAD_COUNT, PYTHON_ISOLATE_WORKER_DEPENDENCIES, PYTHON_ENABLE_DEBUG_LOGGING, + PYTHON_ENABLE_WORKER_EXTENSIONS, FUNCTIONS_WORKER_SHARED_MEMORY_DATA_TRANSFER_ENABLED] app_setting_states = "".join( From e19496d08489b5808f803f93ff259c4597de66b2 Mon Sep 17 00:00:00 2001 From: hallvictoria Date: Tue, 14 Nov 2023 14:44:05 -0600 Subject: [PATCH 11/12] removed comma --- azure_functions_worker/dispatcher.py | 4 ++-- tests/unittests/test_app_setting_manager.py | 8 ++++---- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/azure_functions_worker/dispatcher.py b/azure_functions_worker/dispatcher.py index c54270caa..625397f5b 100644 --- a/azure_functions_worker/dispatcher.py +++ b/azure_functions_worker/dispatcher.py @@ -552,11 +552,11 @@ async def _handle__function_environment_reload_request(self, request): try: logger.info('Received FunctionEnvironmentReloadRequest, ' 'request ID: %s,' - 'App Settings state: %s.', + 'App Settings state: %s.' ' To enable debug level logging, please refer to ' 'https://aka.ms/python-enable-debug-logging', self.request_id, - "test") + get_python_appsetting_state()) func_env_reload_request = \ request.function_environment_reload_request diff --git a/tests/unittests/test_app_setting_manager.py b/tests/unittests/test_app_setting_manager.py index 815727fb6..8a2e3b1f6 100644 --- a/tests/unittests/test_app_setting_manager.py +++ b/tests/unittests/test_app_setting_manager.py @@ -88,7 +88,7 @@ async def test_initialize_worker_logging(self): def test_get_python_appsetting_state(self): app_setting_state = get_python_appsetting_state() - expected_string = ("PYTHON_THREADPOOL_THREAD_COUNT: 20 " - "PYTHON_ENABLE_DEBUG_LOGGING: 1 " - "PYTHON_ENABLE_WORKER_EXTENSIONS: ") - self.assertIn(expected_string, app_setting_state) + self.assertIn("PYTHON_THREADPOOL_THREAD_COUNT: 20 ", app_setting_state) + self.assertIn("PYTHON_ENABLE_DEBUG_LOGGING: 1 ", app_setting_state) + self.assertIn("PYTHON_ENABLE_WORKER_EXTENSIONS: ", app_setting_state) + From 437cefec5cb167c47ced95fb63c3bc0150d881d7 Mon Sep 17 00:00:00 2001 From: hallvictoria Date: Tue, 14 Nov 2023 14:53:46 -0600 Subject: [PATCH 12/12] FLAKE --- tests/unittests/test_app_setting_manager.py | 1 - 1 file changed, 1 deletion(-) diff --git a/tests/unittests/test_app_setting_manager.py b/tests/unittests/test_app_setting_manager.py index 8a2e3b1f6..7c6650671 100644 --- a/tests/unittests/test_app_setting_manager.py +++ b/tests/unittests/test_app_setting_manager.py @@ -91,4 +91,3 @@ def test_get_python_appsetting_state(self): self.assertIn("PYTHON_THREADPOOL_THREAD_COUNT: 20 ", app_setting_state) self.assertIn("PYTHON_ENABLE_DEBUG_LOGGING: 1 ", app_setting_state) self.assertIn("PYTHON_ENABLE_WORKER_EXTENSIONS: ", app_setting_state) -