User Created Event Loop Not Logging

[maiqbal11]

When the user creates an event loop and runs their function code in it, logs are not generated for functions called within the event loop.

For example, the following code would not log the line Python timer trigger function ran at ...:

import datetime
import logging
import asyncio

import azure.functions as func


async def log_timer_triggered():
    asyncio.sleep(1)
    utc_timestamp = datetime.datetime.utcnow().replace(
        tzinfo=datetime.timezone.utc).isoformat()

    logging.info('Python timer trigger function ran at %s', utc_timestamp)

def main(mytimer: func.TimerRequest) -> None:
    if mytimer.past_due:
        logging.info('The timer is past due!')

    logging.info('main')
    loop = asyncio.SelectorEventLoop()
    asyncio.set_event_loop(loop)
    loop.run_until_complete(log_timer_triggered())
    loop.close()
    logging.info('main done')

However, the following will work fine and logs will be present:

async def log_timer_triggered():
    asyncio.sleep(1)
    utc_timestamp = datetime.datetime.utcnow().replace(
        tzinfo=datetime.timezone.utc).isoformat()

    logging.info('Python timer trigger function ran at %s', utc_timestamp)

def main(mytimer: func.TimerRequest) -> None:
    if mytimer.past_due:
        logging.info('The timer is past due!')

    logging.info('main')
    await log_timer_triggered()
    logging.info('main done')

The former is an async pattern that we do not currently handle as we expect users to run within the loop that we provide. Possible solutions would include either (a) handling user provided event loops or (b) surfacing warnings after detecting this pattern.

[Hazhzeng]

I tested the current behavior in Python 3.6 and 3.7 with HttpTrigger, it reports an actual exception which blocks our user from creating a new event loop in function app. This is an expected behavior.

[1/22/2020 1:24:54 AM] Executed 'Functions.HttpAsyncIo' (Failed, Id=05ff11b9-3e0a-472a-aa14-cc8582d20e4b)
[1/22/2020 1:24:54 AM] System.Private.CoreLib: Exception while executing function: Functions.HttpAsyncIo. System.Private.CoreLib: Result: Failure
Exception: RuntimeError: Cannot run the event loop while another loop is running
Stack:   File "C:\Users\hazeng\AppData\Roaming\npm\node_modules\azure-functions-core-tools\bin\workers\python\3.7\WINDOWS\X64\azure_functions_worker\dispatcher.py", line 308, in _handle__invocation_request
    call_result = await fi.func(**args)
  File "C:\Users\hazeng\Projects\Functions\Python37Dev\HttpAsyncIo\__init__.py", line 17, in main    loop.run_until_complete(doEventLoopLogging())
  File "C:\Users\hazeng\AppData\Local\Programs\Python\Python37\lib\asyncio\base_events.py", line 
566, in run_until_complete
    self.run_forever()
  File "C:\Users\hazeng\AppData\Local\Programs\Python\Python37\lib\asyncio\base_events.py", line 
524, in run_forever
    'Cannot run the event loop while another loop is running')

[SeaDude]

Hello,

The above is a rare example of async Azure Python Functions on the internet. All examples I've seen of the async pattern seems to use the main() function differently than I'm used to.

Instead of the synchronous pattern of:

import azure.functions as func

def main(mytimer: func.TimerRequest) -> None:

#---- Define functions----

    def do_a(arg_a):
        # Insert work here
        return foo
    
    def do_b(arg_b):
        # Insert work here
        return bar

#---- Define variables----

    arg_a = 'yay'
    arb_b = 'yea'

#---- Call functions----

    a = do_a(arg_a)
    b = do_b(arg_b)

Aside from the Azure-python-sdk examples (which all show this method too), is there any documentation on why the main() function is used in such a way?

The Azure Function docs say "Use async" and the examples show it, but I would love to hear why. Especially when there appear to be "things" going on behind the scenes that are not apparent.