Categorize SDK logs as system logs (#850)
* Add testing for cases * Amend expected behavior
This commit is contained in:
Hanzhang Zeng
GitHub
Родитель
473cd1e264
Коммит
a3c047bb01
|
|
@ -9,6 +9,7 @@ import sys
|
|||
# Logging Prefixes
|
||||
CONSOLE_LOG_PREFIX = "LanguageWorkerConsoleLog"
|
||||
SYSTEM_LOG_PREFIX = "azure_functions_worker"
|
||||
SDK_LOG_PREFIX = "azure.functions"
|
||||
|
||||
|
||||
logger: logging.Logger = logging.getLogger('azure_functions_worker')
|
||||
|
|
@ -76,6 +77,15 @@ def enable_console_logging() -> None:
|
|||
|
||||
|
||||
def is_system_log_category(ctg: str) -> bool:
|
||||
# Category starts with 'azure_functions_worker' or
|
||||
# 'azure_functions_worker_errors' will be treated as system logs
|
||||
return ctg.lower().startswith(SYSTEM_LOG_PREFIX)
|
||||
"""Check if the logging namespace belongs to system logs. Category starts
|
||||
with the following name will be treated as system logs.
|
||||
1. 'azure_functions_worker' (Worker Info)
|
||||
2. 'azure_functions_worker_errors' (Worker Error)
|
||||
3. 'azure.functions' (SDK)
|
||||
|
||||
Expected behaviors for sytem logs and customer logs are listed below:
|
||||
local_console customer_app_insight functions_kusto_table
|
||||
system_log false false true
|
||||
customer_log true true false
|
||||
"""
|
||||
return ctg.startswith(SYSTEM_LOG_PREFIX) or ctg.startswith(SDK_LOG_PREFIX)
|
||||
|
|
|
|||
|
|
@ -0,0 +1,16 @@
|
|||
# Copyright (c) Microsoft Corporation. All rights reserved.
|
||||
# Licensed under the MIT License.
|
||||
import logging
|
||||
|
||||
import azure.functions as func
|
||||
|
||||
|
||||
sdk_logger = logging.getLogger('azure.functions')
|
||||
|
||||
|
||||
def main(req: func.HttpRequest):
|
||||
sdk_logger.info('sdk_logger info')
|
||||
sdk_logger.warning('sdk_logger warning')
|
||||
sdk_logger.debug('sdk_logger debug')
|
||||
sdk_logger.error('sdk_logger error', exc_info=True)
|
||||
return 'OK-sdk-logger'
|
||||
|
|
@ -0,0 +1,16 @@
|
|||
{
|
||||
"scriptFile": "__init__.py",
|
||||
"bindings": [
|
||||
{
|
||||
"type": "httpTrigger",
|
||||
"direction": "in",
|
||||
"name": "req"
|
||||
},
|
||||
{
|
||||
"type": "http",
|
||||
"direction": "out",
|
||||
"name": "$return"
|
||||
}
|
||||
],
|
||||
"entryPoint": "main"
|
||||
}
|
||||
|
|
@ -0,0 +1,16 @@
|
|||
# Copyright (c) Microsoft Corporation. All rights reserved.
|
||||
# Licensed under the MIT License.
|
||||
import logging
|
||||
|
||||
import azure.functions as func
|
||||
|
||||
|
||||
sdk_submodule_logger = logging.getLogger('azure.functions.submodule')
|
||||
|
||||
|
||||
def main(req: func.HttpRequest):
|
||||
sdk_submodule_logger.info('sdk_submodule_logger info')
|
||||
sdk_submodule_logger.warning('sdk_submodule_logger warning')
|
||||
sdk_submodule_logger.debug('sdk_submodule_logger debug')
|
||||
sdk_submodule_logger.error('sdk_submodule_logger error', exc_info=True)
|
||||
return 'OK-sdk-submodule-logging'
|
||||
|
|
@ -0,0 +1,16 @@
|
|||
{
|
||||
"scriptFile": "__init__.py",
|
||||
"bindings": [
|
||||
{
|
||||
"type": "httpTrigger",
|
||||
"direction": "in",
|
||||
"name": "req"
|
||||
},
|
||||
{
|
||||
"type": "http",
|
||||
"direction": "out",
|
||||
"name": "$return"
|
||||
}
|
||||
],
|
||||
"entryPoint": "main"
|
||||
}
|
||||
|
|
@ -1,6 +1,5 @@
|
|||
# Copyright (c) Microsoft Corporation. All rights reserved.
|
||||
# Licensed under the MIT License.
|
||||
|
||||
import typing
|
||||
|
||||
from azure_functions_worker import testutils
|
||||
|
|
@ -20,6 +19,15 @@ HOST_JSON_TEMPLATE_WITH_LOGLEVEL_INFO = """\
|
|||
|
||||
|
||||
class TestLogFilteringFunctions(testutils.WebHostTestCase):
|
||||
"""This class is for testing the logger behavior in Python Worker when
|
||||
dealing with customer's log and system's log. Here's a list of expected
|
||||
behaviors:
|
||||
local_console customer_app_insight functions_kusto_table
|
||||
system_log false false true
|
||||
customer_log true true false
|
||||
|
||||
Please ensure the following unit test cases align with the expectations
|
||||
"""
|
||||
|
||||
@classmethod
|
||||
def setUpClass(cls):
|
||||
|
|
@ -50,6 +58,7 @@ class TestLogFilteringFunctions(testutils.WebHostTestCase):
|
|||
self.assertIn('logging info', host_out)
|
||||
self.assertIn('logging warning', host_out)
|
||||
self.assertIn('logging error', host_out)
|
||||
# See HOST_JSON_TEMPLATE_WITH_LOGLEVEL_INFO, debug log is disabled
|
||||
self.assertNotIn('logging debug', host_out)
|
||||
|
||||
def test_debug_with_user_logging(self):
|
||||
|
|
@ -61,4 +70,40 @@ class TestLogFilteringFunctions(testutils.WebHostTestCase):
|
|||
self.assertIn('logging info', host_out)
|
||||
self.assertIn('logging warning', host_out)
|
||||
self.assertIn('logging error', host_out)
|
||||
# See HOST_JSON_TEMPLATE_WITH_LOGLEVEL_INFO, debug log is disabled
|
||||
self.assertNotIn('logging debug', host_out)
|
||||
|
||||
def test_info_with_sdk_logging(self):
|
||||
"""Invoke a HttpTrigger sdk_logging which contains logging invocation
|
||||
via the azure.functions logger. This should be treated as system logs,
|
||||
which means the log should not be displayed in local console.
|
||||
"""
|
||||
r = self.webhost.request('GET', 'sdk_logging')
|
||||
self.assertEqual(r.status_code, 200)
|
||||
self.assertEqual(r.text, 'OK-sdk-logger')
|
||||
|
||||
def check_log_info_with_sdk_logging(self, host_out: typing.List[str]):
|
||||
# See TestLogFilteringFunctions docstring
|
||||
# System log should not be captured in console
|
||||
self.assertNotIn('sdk_logger info', host_out)
|
||||
self.assertNotIn('sdk_logger warning', host_out)
|
||||
self.assertNotIn('sdk_logger error', host_out)
|
||||
self.assertNotIn('sdk_logger debug', host_out)
|
||||
|
||||
def test_info_with_sdk_submodule_logging(self):
|
||||
"""Invoke a HttpTrigger sdk_submodule_logging which contains logging
|
||||
invocation via the azure.functions logger. This should be treated as
|
||||
system logs.
|
||||
"""
|
||||
r = self.webhost.request('GET', 'sdk_submodule_logging')
|
||||
self.assertEqual(r.status_code, 200)
|
||||
self.assertEqual(r.text, 'OK-sdk-submodule-logging')
|
||||
|
||||
def check_log_info_with_sdk_submodule_logging(self,
|
||||
host_out: typing.List[str]):
|
||||
# See TestLogFilteringFunctions docstring
|
||||
# System log should not be captured in console
|
||||
self.assertNotIn('sdk_submodule_logger info', host_out)
|
||||
self.assertNotIn('sdk_submodule_logger warning', host_out)
|
||||
self.assertNotIn('sdk_submodule_logger error', host_out)
|
||||
self.assertNotIn('sdk_submodule_logger debug', host_out)
|
||||
|
|
|
|||
|
|
@ -0,0 +1,35 @@
|
|||
# Copyright (c) Microsoft Corporation. All rights reserved.
|
||||
# Licensed under the MIT License.
|
||||
import unittest
|
||||
|
||||
from azure_functions_worker import logging as flog
|
||||
|
||||
|
||||
class TestLogging(unittest.TestCase):
|
||||
"""This class is for testing the grpc logging behavior in Python Worker.
|
||||
Here's a list of expected behaviors:
|
||||
local_console customer_app_insight functions_kusto_table
|
||||
system_log false false true
|
||||
customer_log true true false
|
||||
|
||||
Please ensure the following unit test cases align with the expectations
|
||||
"""
|
||||
|
||||
def test_system_log_namespace(self):
|
||||
"""Ensure the following list is part of the system's log
|
||||
"""
|
||||
self.assertTrue(flog.is_system_log_category('azure_functions_worker'))
|
||||
self.assertTrue(
|
||||
flog.is_system_log_category('azure_functions_worker_error')
|
||||
)
|
||||
self.assertTrue(flog.is_system_log_category('azure.functions'))
|
||||
self.assertTrue(flog.is_system_log_category('azure.functions.module'))
|
||||
|
||||
def test_customer_log_namespace(self):
|
||||
"""Ensure the following list is part of the customer's log
|
||||
"""
|
||||
self.assertFalse(flog.is_system_log_category('customer_logger'))
|
||||
self.assertFalse(flog.is_system_log_category('azure'))
|
||||
self.assertFalse(flog.is_system_log_category('protobuf'))
|
||||
self.assertFalse(flog.is_system_log_category('root'))
|
||||
self.assertFalse(flog.is_system_log_category(''))
|
||||
|
|
@ -0,0 +1,91 @@
|
|||
# Copyright (c) Microsoft Corporation. All rights reserved.
|
||||
# Licensed under the MIT License.
|
||||
from unittest.mock import patch, call
|
||||
|
||||
from azure_functions_worker import testutils, protos
|
||||
from azure_functions_worker.logging import is_system_log_category
|
||||
|
||||
|
||||
class TestMockLogFilteringFunctions(testutils.AsyncTestCase):
|
||||
dir = testutils.UNIT_TESTS_FOLDER / 'log_filtering_functions'
|
||||
|
||||
async def test_root_logger_should_be_customer_log(self):
|
||||
"""When customer use the root logger to send logs, the 'root' namespace
|
||||
should be treated as customer log, only sending to our customers.
|
||||
"""
|
||||
with patch(
|
||||
'azure_functions_worker.dispatcher.is_system_log_category'
|
||||
) as islc_mock:
|
||||
async with testutils.start_mockhost(script_root=self.dir) as host:
|
||||
await host.load_function('debug_logging')
|
||||
await self._invoke_function(host, 'debug_logging')
|
||||
|
||||
self.assertIn(call('root'), islc_mock.call_args_list)
|
||||
self.assertFalse(is_system_log_category('root'))
|
||||
|
||||
async def test_customer_logging_should_not_be_system_log(self):
|
||||
"""When sdk uses the 'azure' logger to send logs
|
||||
(e.g. 'azure.servicebus'), the namespace should be treated as customer
|
||||
log, only sends to our customers.
|
||||
"""
|
||||
with patch(
|
||||
'azure_functions_worker.dispatcher.is_system_log_category'
|
||||
) as islc_mock:
|
||||
async with testutils.start_mockhost(script_root=self.dir) as host:
|
||||
await host.load_function('debug_user_logging')
|
||||
await self._invoke_function(host, 'debug_user_logging')
|
||||
|
||||
self.assertIn(call('my function'), islc_mock.call_args_list)
|
||||
self.assertFalse(is_system_log_category('my function'))
|
||||
|
||||
async def test_sdk_logger_should_be_system_log(self):
|
||||
"""When sdk uses the 'azure.functions' logger to send logs, the
|
||||
namespace should be treated as system log, sending to our customers and
|
||||
our kusto table.
|
||||
"""
|
||||
with patch(
|
||||
'azure_functions_worker.dispatcher.is_system_log_category'
|
||||
) as islc_mock:
|
||||
async with testutils.start_mockhost(script_root=self.dir) as host:
|
||||
await host.load_function('sdk_logging')
|
||||
await self._invoke_function(host, 'sdk_logging')
|
||||
|
||||
self.assertIn(
|
||||
call('azure.functions'), islc_mock.call_args_list
|
||||
)
|
||||
self.assertTrue(is_system_log_category('azure.functions'))
|
||||
|
||||
async def test_sdk_submodule_logger_should_be_system_log(self):
|
||||
"""When sdk uses the 'azure.functions.submodule' logger to send logs,
|
||||
the namespace should be treated as system log, sending to our customers
|
||||
and our kusto table.
|
||||
"""
|
||||
with patch(
|
||||
'azure_functions_worker.dispatcher.is_system_log_category'
|
||||
) as islc_mock:
|
||||
async with testutils.start_mockhost(script_root=self.dir) as host:
|
||||
await host.load_function('sdk_submodule_logging')
|
||||
await self._invoke_function(host, 'sdk_submodule_logging')
|
||||
|
||||
self.assertIn(
|
||||
call('azure.functions.submodule'), islc_mock.call_args_list
|
||||
)
|
||||
self.assertTrue(
|
||||
is_system_log_category('azure.functions.submodule')
|
||||
)
|
||||
|
||||
async def _invoke_function(self,
|
||||
host: testutils._MockWebHost,
|
||||
function_name: str):
|
||||
_, r = await host.invoke_function(
|
||||
function_name, [
|
||||
protos.ParameterBinding(
|
||||
name='req',
|
||||
data=protos.TypedData(
|
||||
http=protos.RpcHttp(method='GET')
|
||||
)
|
||||
)
|
||||
]
|
||||
)
|
||||
|
||||
self.assertEqual(r.response.result.status, protos.StatusResult.Success)
|
||||
Загрузка…
Ссылка в новой задаче