Skip to content

feature: Add invocation request hooks #757

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
wants to merge 11 commits into from
Closed

feature: Add invocation request hooks #757

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
11 commits
Select commit Hold shift + click to select a range
87aab9a
hooks
lzchen Oct 9, 2020
4dc4d69
Merge branch 'dev' into lzchen/hooks
lzchen Oct 9, 2020
b74bca0
lint
lzchen Oct 14, 2020
cef0f76
Merge branch 'dev' of https://github.com/Azure/azure-functions-python…
lzchen Oct 14, 2020
7d468e5
Update dispatcher.py
lzchen Oct 14, 2020
c21d866
tests
lzchen Oct 14, 2020
ccc8299
Merge branch 'dev' of https://github.com/Azure/azure-functions-python…
lzchen Oct 14, 2020
c4a6a56
lint
lzchen Oct 14, 2020
d49405c
Update test_extensions.py
lzchen Oct 14, 2020
9e4761f
Merge branch 'dev' into lzchen/hooks
vrdmr Jan 28, 2021
b96e614
Merge branch 'dev' into lzchen/hooks
lzchen Feb 2, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
24 changes: 22 additions & 2 deletions azure_functions_worker/dispatcher.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,8 @@
PYTHON_THREADPOOL_THREAD_COUNT_DEFAULT,
PYTHON_THREADPOOL_THREAD_COUNT_MAX,
PYTHON_THREADPOOL_THREAD_COUNT_MIN)
from .extensions import (get_before_invocation_request_callbacks,
get_after_invocation_request_callbacks)
from .logging import disable_console_logging, enable_console_logging
from .logging import error_logger, is_system_log_category, logger
from .utils.common import get_app_setting
Expand Down Expand Up @@ -359,9 +361,19 @@ async def _handle__invocation_request(self, req):
trigger_metadata=trigger_metadata,
pytype=pb_type_info.pytype)

context = bindings.Context(
fi.name, fi.directory, invocation_id, trace_context)

# Execute before invocation callbacks
for callback in get_before_invocation_request_callbacks():
try:
callback(context)
except Exception as ex:
logger.warning(
"Before invocation callback failed with: %s.", ex)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lzchen @Hazhzeng - How is this exposed to the user?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Specifically - is this a USER log or System log? I think its system and won't be shown to the user. @Hazhzeng could you please confirm.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This logger is a system log. Yes, it won't be shown to user.


if fi.requires_context:
args['context'] = bindings.Context(
fi.name, fi.directory, invocation_id, trace_context)
args['context'] = context

if fi.output_types:
for name in fi.output_types:
Expand Down Expand Up @@ -402,6 +414,14 @@ async def _handle__invocation_request(self, req):
fi.return_type.binding_name, call_result,
pytype=fi.return_type.pytype)

# Execute after invocation callbacks
for callback in get_after_invocation_request_callbacks():
try:
callback(context)
except Exception as ex:
logger.warning(
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same here.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah same, this is system log. For extension to expose the log to users, they need to define a new logger without the azure_functions_worker prefix.

import logging

logger = logging.getLogger('SomeExtension')
logger.info('xxx')

"After invocation callback failed with: %s.", ex)

# Actively flush customer print() function to console
sys.stdout.flush()

Expand Down
36 changes: 36 additions & 0 deletions azure_functions_worker/extensions.py
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,36 @@
# Copyright (c) Microsoft Corporation. All rights reserved.
# Licensed under the MIT License.

_EXTENSIONS_CONTEXT = dict()
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@Hazhzeng @lzchen - I don't know the internal details or discussions of the feature, but wouldn't a function.json would have been a better approach for this? To make the contract clearer for all the languages?

My issue (not strong though) is still with this design choice - to import this - as this isn't the convention and this would start new precedence.

from azure_functions_worker.extensions import register_before_invocation_request, register_after_invocation_request

Can you explain an example app - I am assuming azure_functions_worker would be added to the requirements.txt and then using the extensions view.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So the scenario in which we are trying to light up is that incoming requests to the user's function won't be correlated with dependency calls made within the user's function when collecting telemetry via Opencensus. Currently, our workaround is to tell users to connect the telemetry manually by setting the used tracer (Opencensus uses a tracer object to enable distributed tracing), into the passed in context that is received in the function header: def main(req: func.HttpRequest, context: func.Context) -> func.HttpResponse: as well as extracting the context from the headers.

In order to not have to have the user call this manually in their functions app, we have discussed implementing the ability to attach function hooks in the functions worker, which can run code before/after running a user's function. With this, we can run the "connecting traces" logic right before the user's function is run as shown in the example in the PR description.

The example above simply shows how this can be done in code. It is not what we expect the customers to do because we will be planning on adding this "hook" logic (callback) in the Opencensus code upon initiation of the AzureExporter. This means that Opencensus will take a dependency on azure-functions-worker, attach a callback function with the hook on initiation and users will only have to manually set the tracer to be the current tracer in their functions app.

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@lzchen After this PR is merged, what and how is going to invoke register_before_invocation_request and register_after_invocation_request? From the description and the sample, my impression is that this is going to be up to the function app code (which makes this a feature available to the customer). If you don't intend to make app authors do that, how is this supposed to happen? Are you going to clone and modify the worker (that would explain everything)? Are we expecting another PR that will actually invoke these from the worker code?



def register_before_invocation_request(callback):
if _EXTENSIONS_CONTEXT.get("BEFORE_INVOCATION_REQUEST_CALLBACKS"):
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please make BEFORE_INVOCATION_REQUEST_CALLBACKS and AFTER_INVOCATION_REQUEST_CALLBACKS as private variables itself rather than raw strings here.

Also - Any specific reason for the long names here? Would this be better?

BEFORE_INVOCATION_CALLBACKS
AFTER_INVOCATION_CALLBACKS

_EXTENSIONS_CONTEXT.get(
"BEFORE_INVOCATION_REQUEST_CALLBACKS").append(callback)
else:
_EXTENSIONS_CONTEXT["BEFORE_INVOCATION_REQUEST_CALLBACKS"] = [callback]


def register_after_invocation_request(callback):
if _EXTENSIONS_CONTEXT.get("AFTER_INVOCATION_REQUEST_CALLBACKS"):
_EXTENSIONS_CONTEXT.get(
"AFTER_INVOCATION_REQUEST_CALLBACKS").append(callback)
else:
_EXTENSIONS_CONTEXT["AFTER_INVOCATION_REQUEST_CALLBACKS"] = [callback]


def clear_before_invocation_request_callbacks():
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For all the functions in here, please add py-doc strings.

def function():
  """Doc here
  """

_EXTENSIONS_CONTEXT.pop("BEFORE_INVOCATION_REQUEST_CALLBACKS", None)


def clear_after_invocation_request_callbacks():
_EXTENSIONS_CONTEXT.pop("AFTER_INVOCATION_REQUEST_CALLBACKS", None)


def get_before_invocation_request_callbacks():
return _EXTENSIONS_CONTEXT.get("BEFORE_INVOCATION_REQUEST_CALLBACKS", [])


def get_after_invocation_request_callbacks():
return _EXTENSIONS_CONTEXT.get("AFTER_INVOCATION_REQUEST_CALLBACKS", [])
98 changes: 98 additions & 0 deletions tests/unittests/test_extensions.py
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,98 @@
# Copyright (c) Microsoft Corporation. All rights reserved.
# Licensed under the MIT License.

from unittest import TestCase, mock

from azure_functions_worker import extensions


class TestExtensions(TestCase):
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please add a function test in the test_http_functions file with this approach, to get a more complete test.


def tearDown(self):
extensions._EXTENSIONS_CONTEXT.clear()

def test_register_before_invocation_request(self):
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same comment as above for PyDocs.

Please add a single line for each test to describe what the test is doing.

mock_cb = mock.Mock()
mock_cb2 = mock.Mock()
extensions.register_before_invocation_request(mock_cb)
self.assertEqual(
extensions._EXTENSIONS_CONTEXT
["BEFORE_INVOCATION_REQUEST_CALLBACKS"][0],
mock_cb,
)
extensions.register_before_invocation_request(mock_cb2)
self.assertEqual(
extensions._EXTENSIONS_CONTEXT
["BEFORE_INVOCATION_REQUEST_CALLBACKS"][1],
mock_cb2,
)

def test_register_after_invocation_request(self):
mock_cb = mock.Mock()
mock_cb2 = mock.Mock()
extensions.register_after_invocation_request(mock_cb)
self.assertEqual(
extensions._EXTENSIONS_CONTEXT
["AFTER_INVOCATION_REQUEST_CALLBACKS"][0],
mock_cb,
)
extensions.register_after_invocation_request(mock_cb2)
self.assertEqual(
extensions._EXTENSIONS_CONTEXT
["AFTER_INVOCATION_REQUEST_CALLBACKS"][1],
mock_cb2,
)

def test_clear_before_invocation_request_callbacks(self):
mock_cb = mock.Mock()
extensions.register_before_invocation_request(mock_cb)
self.assertEqual(
extensions._EXTENSIONS_CONTEXT
["BEFORE_INVOCATION_REQUEST_CALLBACKS"][0],
mock_cb,
)
extensions.clear_before_invocation_request_callbacks()
self.assertIsNone(
extensions._EXTENSIONS_CONTEXT.
get("BEFORE_INVOCATION_REQUEST_CALLBACKS"),
)

def test_clear_after_invocation_request_callbacks(self):
mock_cb = mock.Mock()
extensions.register_after_invocation_request(mock_cb)
self.assertEqual(
extensions._EXTENSIONS_CONTEXT
["AFTER_INVOCATION_REQUEST_CALLBACKS"][0],
mock_cb,
)
extensions.clear_after_invocation_request_callbacks()
self.assertIsNone(
extensions._EXTENSIONS_CONTEXT.
get("AFTER_INVOCATION_REQUEST_CALLBACKS"),
)

def test_get_before_invocation_request_callbacks(self):
mock_cb = mock.Mock()
extensions.register_before_invocation_request(mock_cb)
self.assertEqual(
extensions._EXTENSIONS_CONTEXT
["BEFORE_INVOCATION_REQUEST_CALLBACKS"][0],
mock_cb,
)
self.assertEqual(
extensions.get_before_invocation_request_callbacks()[0],
mock_cb
)

def test_get_after_invocation_request_callbacks(self):
mock_cb = mock.Mock()
extensions.register_after_invocation_request(mock_cb)
self.assertEqual(
extensions._EXTENSIONS_CONTEXT
["AFTER_INVOCATION_REQUEST_CALLBACKS"][0],
mock_cb,
)
self.assertEqual(
extensions.get_after_invocation_request_callbacks()[0],
mock_cb
)