search

Azure / azure-functions-python-worker

Python worker for Azure Functions.
http://aka.ms/azurefunctions
MIT License
333 stars 103 forks source link

[BUG] Azure China - opencensus-ext-azure causes Python3.9 function to be in a crash loop with "Azure Function Runtime is not Available" #1214

Closed jocortems closed 1 year ago

jocortems commented 1 year ago

Investigative information

Please provide the following:

Repro steps

Provide the steps required to reproduce the problem:

Add "opencensus-ext-azure" to requirements.txt and publish the function. The function code is irrelevant and the module doesn't need to be called in the code, just by installing the module the function crashes.

I am trying to add instrumentation to an existing app I have deployed in an Azure Function in Azure China, the function is working fine but Azure China doesn't support codeless integration with Application Insights, after trying to instrument the function with opencensus extension for Azure monitor I noticed my function was constantly crashing so I trimmed down the code to understand what was causing it to crash, what I discovered is that just by adding the module "opencensus-ext-azure" to the requirements file and publishing the function app it crashes. My requirements.txt file looks like follows, and I didn't make any changes to the existing code (tested and working):

azure-functions
azure-common==1.1.23
azure-identity==1.7.1
azure-mgmt-compute==23.1.0
azure-mgmt-network==19.3.0
azure-mgmt-resource==20.0.0
azure-storage-blob==12.9.0
azure-keyvault-secrets==4.3.0
msrestazure==0.6.4
requests==2.26.0
retry==0.9.2
urllib3==1.26.7
opencensus-ext-azure

The other thing I tried is, with the working code deployed and function running, I SSH'ed into the function worker and manually created the requirements.txt file (same as above) and a func.py that is a copy of the working code but uses opencensus extension for Azure and AzureLogHandler and is run as a script directly from shell (no triggers and bindings):

import json
import logging
import os
import time
import azure.functions as func
import requests
import urllib3
from . import version
from msrestazure.azure_cloud import AZURE_CHINA_CLOUD as CLOUD
from azure.identity import ManagedIdentityCredential
from azure.keyvault.secrets import SecretClient
from azure.mgmt.compute import ComputeManagementClient
from azure.mgmt.network import NetworkManagementClient
from azure.mgmt.resource import SubscriptionClient
from azure.storage.blob import BlobServiceClient
from opencensus.ext.azure.log_exporter import AzureLogHandler
from urllib3.exceptions import InsecureRequestWarning

urllib3.disable_warnings(InsecureRequestWarning)

logger_ha = logging.getLogger('HALOG')
logger_ha.addHandler(
    AzureLogHandler(
        connection_string=os.environ["APPLICATIONINSIGHTS_CONNECTION_STRING"]
    )
)
/// Some code here
def main():
    logging.basicConfig(
        format="%(asctime)s aviatrix-azure-function--- %(message)s",
        level=logging.INFO
    )
    logger_ha.info(
        f"invocation_id")

    event = {
        "aviatrix_api_version": "v1",
        "aviatrix_api_route": "api",
        "tenant_id": os.environ["avx_tenant_id"],
        "client_id": os.environ["avx_client_id"],
        "vault_uri": os.environ["keyvault_uri"],
        "vault_secret": os.environ["keyvault_secret"],
        "func_client_id": os.environ["func_client_id"],
        "storage_name": os.environ["storage_name"],
        "container_name": os.environ["container_name"],
        "lb_name": os.environ["lb_name"],
        "rg": os.environ["resource_group_name"]
    }

    try:
        function_handler(event)
    except Exception as err:
        logger_ha.exception(f"Error has occurred: {str(err)}")
    else:
        logger_ha.info("Aviatrix Controller has been initialized successfully")
        logger_ha.info("Loading function completed !!")
        return func.HttpResponse(
            "Failover event completed successfully")

if __name__ == "__main__":
    main()

Running pip install -r requirements.txt followed by phyton3.9 func.py directly from shell within the function worker works perfectly fine, the issue only seems to be when deploying using Azure Core tools with func azure functionapp publish avx-controller-functionapp --build remote --python

The function was deployed using Terraform as follows

resource "azurerm_linux_function_app" "controller_app" {
  name                           = var.function_app_name == "" ? "aviatrix-controller-app-${random_id.aviatrix.hex}" : var.function_app_name
  resource_group_name            = azurerm_resource_group.aviatrix_rg.name
  location                       = azurerm_resource_group.aviatrix_rg.location
  service_plan_id                = azurerm_service_plan.controller_app_service_plan.id
  storage_account_name           = azurerm_storage_account.aviatrix_controller_storage.name
  storage_account_access_key     = azurerm_storage_account.aviatrix_controller_storage.primary_access_key  
  https_only                     = true

  identity {
    type = "UserAssigned"
    identity_ids = [
      azurerm_user_assigned_identity.aviatrix_identity.id
    ]
  }

  app_settings = {
    "APPLICATIONINSIGHTS_CONNECTION_STRING" = azurerm_application_insights.application_insights.connection_string,
    "BUILD_FLAGS"                     = "UseExpressBuild",
    "XDG_CACHE_HOME"                  = "/tmp/.cache",
    "func_client_id"                  = azurerm_user_assigned_identity.aviatrix_identity.client_id,
    "avx_tenant_id"                   = data.azurerm_subscription.current.tenant_id,
    "avx_client_id"                   = var.avtx_service_principal_appid,
    "keyvault_uri"                    = azurerm_key_vault.aviatrix_key_vault.vault_uri,
    "keyvault_secret"                 = azurerm_key_vault_secret.aviatrix_arm_secret.name,
    "storage_name"                    = azurerm_storage_account.aviatrix_controller_storage.name,
    "container_name"                  = azurerm_storage_container.aviatrix_backup_container.name,
    "scaleset_name"                   = var.scale_set_controller_name,
    "lb_name"                         = var.load_balancer_name,
    "resource_group_name"             = azurerm_resource_group.aviatrix_rg.name,
    "AzureWebJobs.Backup.Disabled"    = var.disable_periodic_backup,    
    "PYTHON_ENABLE_WORKER_EXTENSIONS" = "1",
    "FUNCTIONS_WORKER_RUNTIME"        = "python"
  }

  lifecycle {
    ignore_changes = [
      app_settings
    ]
  }

  site_config {
    http2_enabled             = true
    use_32_bit_worker         = false

    application_stack {
      python_version = "3.9"
    }

    app_service_logs {
      disk_quota_mb = 50
      retention_period_days = 1
    }
  }

  depends_on = [
    module.aviatrix_controller_initialize
  ]
}

Expected behavior

Provide a description of the expected behavior.

Function shouldn't be crashing and it can be invoked

Actual behavior

Provide a description of the actual behavior observed.

After publishing the function using Azure Core Tools func azure functionapp publish avx-controller-functionapp --build remote --python the function is constantly crashing with "Azure Function Runtime is not available"

Known workarounds

Provide a description of any known workarounds.

No workarounds

Contents of the requirements.txt file:

Provide the requirements.txt file to help us find out module related issues.
azure-functions
azure-common==1.1.23
azure-identity==1.7.1
azure-mgmt-compute==23.1.0
azure-mgmt-network==19.3.0
azure-mgmt-resource==20.0.0
azure-storage-blob==12.9.0
azure-keyvault-secrets==4.3.0
msrestazure==0.6.4
requests==2.26.0
retry==0.9.2
urllib3==1.26.7
opencensus-ext-azure

Related information

Provide any related information
Source 
import json
import logging
import os
import time
import azure.functions as func
import requests
import urllib3
from . import version
from msrestazure.azure_cloud import AZURE_CHINA_CLOUD as CLOUD
from azure.identity import ManagedIdentityCredential
from azure.keyvault.secrets import SecretClient
from azure.mgmt.compute import ComputeManagementClient
from azure.mgmt.network import NetworkManagementClient
from azure.mgmt.resource import SubscriptionClient
from azure.storage.blob import BlobServiceClient
from opencensus.ext.azure.log_exporter import AzureLogHandler
from urllib3.exceptions import InsecureRequestWarning

urllib3.disable_warnings(InsecureRequestWarning)

logger_ha = logging.getLogger('HALOG')
logger_ha.addHandler(
    AzureLogHandler(
        connection_string=os.environ["APPLICATIONINSIGHTS_CONNECTION_STRING"]
    )
)

default_wait_time_for_apache_wakeup = 300
WAIT_DELAY = 30
INITIAL_SETUP_DELAY = 10
MAXIMUM_BACKUP_AGE = 24 * 3600 * 3  # 3 days

class AviatrixException(Exception):
    def __init__(self, message="Aviatrix Error Message: ..."):
        super(AviatrixException, self).__init__(message)

def function_handler(event):
    aviatrix_api_version = event["aviatrix_api_version"]
    aviatrix_api_route = event["aviatrix_api_route"]
    tenant_id = event["tenant_id"]
    client_id = event["client_id"]
    vault_uri = event["vault_uri"]
    vault_secret = event["vault_secret"]
    func_client_id = event["func_client_id"]
    storage_name = event["storage_name"]
    container_name = event["container_name"]
    lb_name = event["lb_name"]
    rg = event["rg"]
    wait_time = default_wait_time_for_apache_wakeup

    credentials = ManagedIdentityCredential(client_id=func_client_id)
    subscription_client = SubscriptionClient(credentials, base_url=CLOUD.endpoints.resource_manager, credential_scopes=[CLOUD.endpoints.resource_manager + "/.default"])
    subscription = next(subscription_client.subscriptions.list())
    subscription_id = subscription.subscription_id    
    network_client = NetworkManagementClient(credentials, subscription_id, base_url=CLOUD.endpoints.resource_manager, credential_scopes=[CLOUD.endpoints.resource_manager + "/.default"])
    compute_client = ComputeManagementClient(credentials, subscription_id, base_url=CLOUD.endpoints.resource_manager, credential_scopes=[CLOUD.endpoints.resource_manager + "/.default"])
    blob_service_client = BlobServiceClient(f"https://{storage_name}.blob.core.chinacloudapi.cn", credentials)
    container_client = blob_service_client.get_container_client(container_name)
    secret_client = SecretClient(vault_url=f"{vault_uri}", credential=credentials)
    retrieved_secret = secret_client.get_secret(vault_secret)

    cred = {
        'subscription_id': subscription_id,
        'tenant_id': tenant_id,
        'client_id': client_id,
        'client_secret': retrieved_secret.value
    }

    vm_scaleset_client = compute_client.virtual_machine_scale_sets
    vm_res_client = compute_client.virtual_machines
    lb_res_client = network_client.load_balancers
    lb_res_client.base_url = CLOUD.endpoints.resource_manager

    # Get Scaleset Name
    vmScaleSetName = os.environ["scaleset_name"]

    # Get Scaleset attributes
    vm_scale_set = VmScaleSet(vm_scaleset_client, rg, vmScaleSetName)

    # Get VM info in a Scaleset
    inst_name, private_nic_name = vm_scale_set_vm_info(
        vm_res_client, rg, vmScaleSetName)
    logger_ha.info(f'inst_name:{inst_name}')
    logger_ha.info(f'private_nic_name:{private_nic_name}')
    avx_int_conf = VmNetInt(rg, network_client, private_nic_name)
    logger_ha.info(f'avx_int_conf:{avx_int_conf}')
    old_pub_intf_id = avx_int_conf.AvxPubIntID
    logger_ha.info(f'old_pub_intf_id:{old_pub_intf_id}')
    logger_ha.info(avx_int_conf.AvxPubIntID)

    # Check if blob backup file is recent and able to access blob storage
    blob_file = f"CloudN_{avx_int_conf.AvxPrivIntIP}_save_cloudx_config.enc"

    if not is_backup_file_is_recent(blob_file, container_client):
        raise AviatrixException(f"HA event failed. Backup file does not exist "
                                f"or is older than {MAXIMUM_BACKUP_AGE}")

    version_file = (
        f"CloudN_{avx_int_conf.AvxPrivIntIP}_save_cloudx_version.txt")
    logger_ha.info(f"Controller version file name is {version_file}")
    ctrl_version = retrieve_controller_version(version_file, container_client)

    # Get LoadBalacer config prior to public ip removal
    lb = LbConf(lb_res_client, rg, network_client, lb_name)
    hostname = lb.lb_public_ip_prefix

    # Remove public ip Association
    avx_int_conf.rmPubIntIPAssoc()

    # Terminate unhealthy VM
    vm_detail = vm_res_client.get(rg, inst_name, expand='instanceView')

    try:
        terminate_vm(vm_res_client, rg, vm_detail.name)
    except Exception as err:
        logger_ha.warning(str(err))
        logger_ha.info("There are no running VM's in a scale set ")

    # Increasing sku capacity
    logger_ha.info("Increasing sku capacity -> 1")
    vm_scale_set.updateSku()

    # Needs to be dynamic wait time for scaleset to spin up 1 more instance
    time.sleep(WAIT_DELAY)

    # Get new VM info in a Scaleset
    N_inst_name, N_private_nic_name = vm_scale_set_vm_info(
        vm_res_client, rg, vmScaleSetName)
    N_avx_int_conf = VmNetInt(rg, network_client, N_private_nic_name)
    # Check if https access for functions exist

    # Remove new public ip Association with new instance
    N_avx_int_conf.rmPubIntIPAssoc()

    # Add old public ip Association to the new instance
    N_avx_int_conf.addPubIntIPAssoc(old_pub_intf_id)

    # Delete the detached public ip Association to the new instance
    N_avx_int_conf.deletePubIntIP()

    # Wait until the rest API service of Aviatrix Controller is up and running
    logger_ha.info(
        "START: Wait until API server of Aviatrix Controller is up and running"
    )

    api_endpoint_url = (
        f"https://{hostname}/{aviatrix_api_version}/{aviatrix_api_route}"
    )

    wait_until_controller_api_server_is_ready(
        hostname=hostname,
        api_version=aviatrix_api_version,
        api_route=aviatrix_api_route,
        total_wait_time=wait_time,
        interval_wait_time=10,
    )
    logger_ha.info(
        "ENDED: Wait until API server of controller is up and running")

    # Login Aviatrix Controller with username:
    # Admin and password: private ip address and verify login
    logger_ha.info(
        "START: Login Aviatrix Controller as admin using private ip address")
    response = login(
        api_endpoint_url=api_endpoint_url,
        username="admin",
        password=N_avx_int_conf.AvxPrivIntIP,
        hide_password=True,
    )

    verify_aviatrix_api_response_login(response=response)
    CID = response.json()["CID"]
    logger_ha.info(
        "END: Login Aviatrix Controller as admin using private ip address")

    # Check if the controller has been initialized or not
    logger_ha.info(
        "START: Check if Aviatrix Controller has already been initialized")
    is_controller_initialized = has_controller_initialized(
        api_endpoint_url=api_endpoint_url,
        CID=CID,
    )

    if is_controller_initialized:
        err_msg = "ERROR: Controller has already been initialized"
        logger_ha.error(err_msg)
        raise AviatrixException(message=err_msg)

    logger_ha.info(
        "END: Check if Aviatrix Controller has already been initialized")

    # Initial Setup for Aviatrix Controller by Invoking Aviatrix API
    logger_ha.info("Start: Aviatrix Controller initial setup")
    response = run_initial_setup(
        api_endpoint_url=api_endpoint_url,
        CID=CID,
        target_version=ctrl_version,
    )
    verify_aviatrix_api_run_initial_setup(response=response)
    logger_ha.info("End: Aviatrix Controller initial setup")

    # Wait until apache server of controller is up and running after
    # initial setup.
    logger_ha.info(
        ("START: Wait until API server of Aviatrix Controller "
         "is up and running after initial setup")
    )
    wait_until_controller_api_server_is_ready(
        hostname=hostname,
        api_version=aviatrix_api_version,
        api_route=aviatrix_api_route,
        total_wait_time=wait_time,
        interval_wait_time=10,
    )
    logger_ha.info(
        ("End: Wait until API server of Aviatrix Controller "
         "is up and running after initial setup")
    )

    # Re-login
    logger_ha.info("START: Re-login")
    response = login(
        api_endpoint_url=api_endpoint_url,
        username="admin",
        password=N_avx_int_conf.AvxPrivIntIP,
    )
    verify_aviatrix_api_response_login(response=response)
    CID = response.json()["CID"]
    logger_ha.info("END: Re-login")

    # Restore backup
    logger_ha.info("START: Restore-Backup")
    restore_ctrl_backup(cred, hostname, CID, storage_name,
                        container_name, blob_file)
    logger_ha.info("END: Restore-Backup")

def wait_until_controller_api_server_is_ready(
    hostname="123.123.123.123",
    api_version="v1",
    api_route="api",
    total_wait_time=300,
    interval_wait_time=10,
):
    payload = {"action": "login", "username": "test", "password": "test"}
    api_endpoint_url = f"https://{hostname}/{api_version}/{api_route}"

    # invoke the aviatrix api with a non-existed api
    # to resolve the issue where server status code is 200 but response
    # message is "Valid action required: login"
    # which means backend is not ready yet
    payload = {"action": "login", "username": "test", "password": "test"}
    remaining_wait_time = total_wait_time

    """ Variable Description: (time_spent_for_requests_lib_timeout)
    Description:
        * This value represents how many seconds for "requests" lib to timeout
          by default.
    Detail:
        * The value 20 seconds is actually a rough number
        * If there is a connection error and causing timeout when
          invoking--> requests.get(xxx), it takes about 20 seconds for
          requests.get(xxx) to throw timeout exception.
        * When calculating the remaining wait time, this value is considered.
    """
    time_spent_for_requests_lib_timeout = 20
    last_err_msg = ""
    while remaining_wait_time > 0:
        try:
            # Reset the checking flags
            response_status_code = -1
            is_apache_returned_200 = False
            is_api_service_ready = False

            # invoke a dummy REST API to Aviatrix controller
            response = requests.post(
                url=api_endpoint_url, data=payload, verify=False)

            # check response
            # if the server is ready, the response code should be 200.
            # there are two cases that the response code is 200
            #   case1 : return value is false and the reason message is
            #           "Valid action required: login",
            #           which means the server is not ready yet
            #   case2 : return value is false and the reason message is
            #           "username and password do not match",
            #           which means the server is ready
            if response is not None:
                response_status_code = response.status_code
                logger_ha.info(f"Server status code is: "
                             f"{str(response_status_code)}")
                py_dict = response.json()
                if 'CID' in py_dict:
                    py_dict["CID"] = "*********"
                if response.status_code == 200:
                    is_apache_returned_200 = True

                response_message = py_dict["reason"]
                response_msg_indicates_backend_not_ready = ("Valid action "
                                                            "required")
                response_msg_request_refused = "RequestRefused"
                # case1:
                if (
                    py_dict["return"] is False
                    and (
                        response_msg_indicates_backend_not_ready
                        in response_message
                        or response_msg_request_refused in response_message
                        )
                ):
                    is_api_service_ready = False
                    logger_ha.info(
                        f"Server is not ready, and the response is "
                        f":{response_message}")
                # case2:
                else:
                    is_api_service_ready = True
            # END outer if

            # if the response code is 200 and the server is ready
            if is_apache_returned_200 and is_api_service_ready:
                logger_ha.info("Server is ready")
                return True
        except Exception as e:
            logger_ha.exception(
                f"Aviatrix Controller {api_endpoint_url} is not available")
            last_err_msg = str(e)
            pass
            # END try-except

            # handle the response code is 404
            if response_status_code == 404:
                err_msg = (
                    f"Error: Aviatrix Controller returns error code: 404 for "
                    f"{api_endpoint_url}"
                )
                raise AviatrixException(
                    message=err_msg,
                )
            # END if

        # if server response code is neither 200 nor 404,
        # some other errors occurs
        # repeat the process till reaches case 2

        remaining_wait_time = (
            remaining_wait_time
            - interval_wait_time
            - time_spent_for_requests_lib_timeout
        )
        if remaining_wait_time > 0:
            time.sleep(interval_wait_time)
    # END while loop

    # if the server is still not ready after the default time
    # raise AviatrixException
    err_msg = (
        f"Aviatrix Controller {api_endpoint_url} is not available after "
        f"{str(total_wait_time)} seconds "
        f"Server status code is: {str(response_status_code)}. "
        f"The response message is: {last_err_msg}."
    )
    raise AviatrixException(
        message=err_msg,
    )

# END wait_until_controller_api_server_is_ready()

def verify_aviatrix_api_response_login(response=None):
    # if successfully login
    # response_code == 200
    # api_return_boolean == true
    # response_message = "authorized successfully"

    py_dict = response.json()
    if 'CID' in py_dict:
        py_dict["CID"] = "*********"
    logger_ha.info(f"Aviatrix API response is {str(py_dict)}")

    response_code = response.status_code
    if response_code != 200:
        err_msg = (
            f"Fail to login Aviatrix Controller. The response code is "
            f"{response_code}"
        )
        raise AviatrixException(message=err_msg)

    api_return_boolean = py_dict["return"]
    if api_return_boolean is not True:
        err_msg = (
            f"Fail to Login Aviatrix Controller. The Response is "
            f"{str(py_dict)}"
        )
        raise AviatrixException(
            message=err_msg,
        )

    api_return_msg = py_dict["results"]
    expected_string = "authorized successfully"
    if (expected_string in api_return_msg) is not True:
        err_msg = (
            f"Fail to Login Aviatrix Controller. The Response is "
            f"{str(py_dict)}"
        )
        raise AviatrixException(
            message=err_msg,
        )

# End def verify_aviatrix_api_response_login()

def login(
    api_endpoint_url="https://123.123.123.123/v1/api",
    username="admin",
    password="********",
    hide_password=True,
):
    request_method = "POST"
    data = {"action": "login", "username": username, "password": password}
    logger_ha.info(f"API endpoint url is : {api_endpoint_url}")
    logger_ha.info(f"Request method is : {request_method}")

    # handle if the hide_password is selected
    if hide_password:
        payload_with_hidden_password = dict(data)
        payload_with_hidden_password["password"] = "************"
        logger_ha.info(
            f"Request payload: "
            f"{str(json.dumps(obj=payload_with_hidden_password, indent=4))}")
    else:
        logger_ha.info(f"Request payload: "
                     f"{str(json.dumps(obj=data, indent=4))}")

    # send post request to the api endpoint
    response = send_aviatrix_api(
        api_endpoint_url=api_endpoint_url,
        request_method=request_method,
        payload=data,
    )
    return response

# End def login()

def send_aviatrix_api(
    api_endpoint_url="https://123.123.123.123/v1/api",
    request_method="POST",
    payload=dict(),
    retry_count=5,
    timeout=None,
):
    response = None
    responses = list()
    request_type = request_method.upper()
    response_status_code = -1

    for i in range(retry_count):
        try:
            if request_type == "GET":
                response = requests.get(
                    url=api_endpoint_url, params=payload, verify=False
                )
                response_status_code = response.status_code
            elif request_type == "POST":
                response = requests.post(
                    url=api_endpoint_url, data=payload,
                    verify=False, timeout=timeout
                )
                response_status_code = response.status_code
            else:
                failure_reason = (f"ERROR : Bad HTTPS request type: "
                                  f"{request_type}")
                logger_ha.error(failure_reason)
        except requests.exceptions.Timeout as e:
            logger_ha.warning(f"WARNING: Request timeout... {str(e)}")
            responses.append(str(e))
        except requests.exceptions.ConnectionError as e:
            logger_ha.warning(f"WARNING: Server is not responding... {str(e)}")
            responses.append(str(e))
        except Exception as e:
            logger_ha.warning(f"HTTP request failed {str(e)}")
            # For error message/debugging purposes

        finally:
            if response_status_code == 200:
                return response
            elif response_status_code == 404:
                failure_reason = "ERROR: 404 Not Found"
                logger_ha.error(failure_reason)

            # if the response code is neither 200 nor 404, retry process
            # the default retry count is 5, the wait for each retry is i
            # i           =  0  1  2  3  4
            # wait time   =     1  2  4  8

            if i + 1 < retry_count:
                logger_ha.info("START: retry")
                logger_ha.info("i == %d", i)
                wait_time_before_retry = pow(2, i)
                logger_ha.info("Wait for: %ds for the next retry",
                             wait_time_before_retry)
                time.sleep(wait_time_before_retry)
                logger_ha.info("ENDED: Wait until retry")
                # continue next iteration
            else:
                failure_reason = (
                    f"ERROR: Failed to invoke Aviatrix API. Exceed the max "
                    f"retry times. All responses are listed as follows: "
                    f"{str(responses)}"
                )
                raise AviatrixException(
                    message=failure_reason,
                )
            # END
    return response

# End def send_aviatrix_api()

def verify_aviatrix_api_run_initial_setup(response=None):
    if not response:
        return
    py_dict = response.json()
    if 'CID' in py_dict:
        py_dict["CID"] = "*********"
    logger_ha.info(f"Aviatrix API response is: {str(py_dict)}")

    response_code = response.status_code
    if response_code != 200:
        err_msg = (
            f"Fail to run initial setup for the Aviatrix Controller. "
            f"The actual response code is "
            f"{str(response_code)}, which is not 200"
        )
        raise AviatrixException(message=err_msg)

    api_return_boolean = py_dict["return"]
    if api_return_boolean is not True:
        err_msg = (
            f"Fail to run initial setup for the Aviatrix Controller. "
            f"The actual api response is "
            f"{str(py_dict)}"
        )
        raise AviatrixException(message=err_msg)
    pass

# End def verify_aviatrix_api_run_initial_setup()

def has_controller_initialized(
    api_endpoint_url="123.123.123.123/v1/api",
    CID="ABCD1234",
):
    request_method = "GET"
    data = {"action": "initial_setup", "subaction": "check", "CID": CID}
    payload_with_hidden_password = dict(data)
    payload_with_hidden_password["CID"] = "************"
    logger_ha.info(f"API endpoint url: {str(api_endpoint_url)}")
    logger_ha.info(f"Request method is: {str(request_method)}")
    logger_ha.info(
        f"Request payload is : "
        f"{str(json.dumps(obj=payload_with_hidden_password, indent=4))}")
    response = send_aviatrix_api(
        api_endpoint_url=api_endpoint_url,
        request_method=request_method,
        payload=data,
    )

    py_dict = response.json()
    if 'CID' in py_dict:
        py_dict["CID"] = "*********"
    logger_ha.info(f"Aviatrix API response is: {str(py_dict)}")

    if py_dict["return"] is False and "not run" in py_dict["reason"]:
        return False
    else:
        return True

# End def has_controller_initialized()

# End def send_aviatrix_api()
class VmScaleSet():
    def __init__(self, vm_ss_client, resource_group, scaleSetName):
        self.vm_ss_client = vm_ss_client
        self.resource_group = resource_group
        self.scaleSetName = scaleSetName
        self.vmScaleSet = vm_ss_client.get(resource_group, scaleSetName)
        self.sku = self.vmScaleSet.sku

    def getSku(self):
        return self.sku

    def updateSku(self):
        try:
            self.vmScaleSet.sku.capacity = 1
            response = self.vm_ss_client.begin_create_or_update(
                self.resource_group, self.scaleSetName, self.vmScaleSet)
            response.wait()
            if response.status() == 'Succeeded':
                logger_ha.info(f"Updated sku capacity: "
                             f"{str(self.vmScaleSet.sku.capacity)}\n")
                # returns {'additional_properties': {},
                # 'name': 'Standard_A4_v2',
                # 'tier': 'Standard',
                # 'capacity': 1}
                return self.sku
        except Exception as err:
            logger_ha.warning(str(err))

# As a prevalidation :
# 1. Make sure eip is asscosiated with controller
# 2. Make sure instance exists if N?A start from updating capacity
# 3. Make sure of using this class only if unhealthy instance exists
class VmNetInt():
    def __init__(self, resource_group, network_client, vm_intf_name):
        self.resource_group = resource_group
        self.network_client = network_client
        self.vm_intf_name = vm_intf_name
        self.Pri_intf_conf = self.network_client.network_interfaces.get(
            resource_group, vm_intf_name)
        self.sg_name = self.Pri_intf_conf.network_security_group.id.split(
            '/')[-1]
        self.ipConfName = self.Pri_intf_conf.name
        self.subnetID = self.Pri_intf_conf.ip_configurations[0].subnet.id
        self.location = self.Pri_intf_conf.location
        self.AvxPrivIntIP = (
            self.Pri_intf_conf.ip_configurations[0].private_ip_address)
        self.AvxPrivIntID = self.Pri_intf_conf.id
        self.AvxPubIntID = (
            self.Pri_intf_conf.ip_configurations[0].public_ip_address.id)
        self.AvxPubIntName = (
            self.Pri_intf_conf.ip_configurations[0].public_ip_address.id.split(
                '/')[-1])
        self.Pub_intf_conf = self.network_client.public_ip_addresses.get(
            self.resource_group, self.AvxPubIntName)
        self.AvxPubIntIP = self.Pub_intf_conf.ip_address

    def rmPubIntIPAssoc(self):
        """ Removes public IP association before vm termination """
        inf_conf_model = self.Pri_intf_conf
        inf_conf_model.ip_configurations[0].public_ip_address = None
        try:
            logger_ha.info(
                f"START: Dissociating {self.AvxPubIntName} : "
                f"{self.AvxPubIntIP} from {self.AvxPrivIntIP}")
            response = (
                self.network_client.network_interfaces.begin_create_or_update(
                    self.resource_group, self.vm_intf_name, inf_conf_model))
            response.wait()
            if response.status() == 'Succeeded':
                logger_ha.info("End: Dissociating completed successfully\n")
        except Exception as err:
            logger_ha.warning(str(err))

    def addPubIntIPAssoc(self, old_public_ip_name):
        """ Associates old public IP to the new vm """
        params = {'id': old_public_ip_name}
        inf_conf_model = self.Pri_intf_conf
        inf_conf_model.ip_configurations[0].public_ip_address = params
        try:
            logger_ha.info(f"START: Associating "
                         f"{old_public_ip_name.split('/')[-1]} "
                         f" with {self.AvxPrivIntIP}")
            response = (
                self.network_client.network_interfaces.begin_create_or_update(
                    self.resource_group, self.vm_intf_name, inf_conf_model))
            response.wait()
            if response.status() == 'Succeeded':
                logger_ha.info("End: Associating completed successfully\n")
        except Exception as err:
            logger_ha.warning(str(err))

    def deletePubIntIP(self):
        """ Deletes the public IP """
        try:
            logger_ha.info(
                f"START: Deleting newly created {self.AvxPubIntName} : "
                f"{self.AvxPubIntIP} from {self.resource_group}")
            response = self.network_client.public_ip_addresses.begin_delete(
                self.resource_group, self.AvxPubIntName)
            response.wait()
            if response.status() == 'Succeeded':
                logger_ha.info("End: Deleting public ip successfully\n")
        except Exception as err:
            logger_ha.warning(str(err))

class LbConf():
    def __init__(self, lb_client, resource_group, network_client, lb_name):
        self.resource_group = resource_group
        self.lb_name = lb_name
        self.network_client = network_client
        self.lb_client_get = lb_client.get(self.resource_group, self.lb_name)
        self.location = self.lb_client_get.location
        self.lb_fe_name = self.lb_client_get.frontend_ip_configurations[0].name
        self.lb_be_name = self.lb_client_get.backend_address_pools[0].name
        self.lb_be_id = self.lb_client_get.backend_address_pools[0].id
        self.lb_be_rules = (
            self.lb_client_get.backend_address_pools[0].load_balancing_rules)
        self.lb_be_type = self.lb_client_get.backend_address_pools[0].type
        self.lb_frontend_ip_config = (
            self.lb_client_get.frontend_ip_configurations[0])
        self.lb_public_ip_name = (
            self.lb_frontend_ip_config.public_ip_address.id.split(
                '/')[-1])
        self.lb_public_ip = self.network_client.public_ip_addresses.get(
            self.resource_group, self.lb_public_ip_name)
        self.lb_public_ip_prefix = self.lb_public_ip.ip_address
        self.lb_be_conf = (
            self.network_client.load_balancer_backend_address_pools.get(
                self.resource_group, self.lb_name, self.lb_be_name))

def terminate_vm(vm_client, resource_group, vm_name):
    """ Terminates a vm in the specified resource group """
    try:
        logger_ha.info(f"START: Terminating instance {vm_name} "
                     f"from resource group {resource_group}")
        response = vm_client.begin_delete(resource_group, vm_name)
        response.wait()
        if response.status() == 'Succeeded':
            logger_ha.info("End: Terminated instance successfully\n")
    except Exception as err:
        logger_ha.warning(str(err))

def vm_scale_set_vm_info(vm_client, resource_group, scaleSetName):
    vm_name = ''
    vm_nic_name = ''
    vmScaleSetVmsLst = vm_client.list(resource_group)
    for vmScaleSetVms in vmScaleSetVmsLst:
        # Searching the VM name by appending scaleset name + _
        if scaleSetName + '_' in vmScaleSetVms.name:
            vm_name = vmScaleSetVms.name
            vm_nic = vmScaleSetVms.network_profile.network_interfaces[0]
            vm_nic_name = vm_nic.id.split('/')[-1]
    return vm_name, vm_nic_name

def run_initial_setup(api_endpoint_url="123.123.123.123/v1/api",
                      CID="ABCD1234", target_version="latest"):

    # Step1 : Check if the controller has been already initialized
    #       --> yes
    #       --> no --> run init setup (upgrading to latest controller version)
    request_method = "POST"
    data = {"action": "initial_setup", "CID": CID, "subaction": "check"}
    logger_ha.info("Check if the initial setup has been already done or not")
    response = send_aviatrix_api(
        api_endpoint_url=api_endpoint_url,
        request_method=request_method,
        payload=data,
    )
    py_dict = response.json()
    if 'CID' in py_dict:
        py_dict["CID"] = "*********"
    # The initial setup has been done
    if py_dict["return"] is True:
        logger_ha.info(
            "Initial setup for Aviatrix Controller has been already done")
        return response

    # The initial setup has not been done yet
    data = {
        "action": "initial_setup",
        "CID": CID,
        "target_version": target_version,
        "subaction": "run",
    }
    payload_with_hidden_password = dict(data)
    payload_with_hidden_password["CID"] = "********"
    logger_ha.info(f"API endpoint url: {str(api_endpoint_url)}")
    logger_ha.info(f"Request method is: {str(request_method)}")
    logger_ha.info(
        f"Request payload is : "
        f"{str(json.dumps(obj=payload_with_hidden_password, indent=4))}")
    try:
        response = send_aviatrix_api(
            api_endpoint_url=api_endpoint_url,
            request_method=request_method,
            payload=data,
            retry_count=1,
            timeout=360,
        )
    except AviatrixException as ae:
        # Ignore timeout exception since it is expected
        if "Read timed out" in str(ae):
            return None
    except Exception as err:
        logger_ha.info(f"Error occurred during initial setup: {str(err)}")
        raise
    return response

# End def run_initial_setup()

def retrieve_controller_version(version_file, container_client):
    """ Get the controller version from backup file"""
    logger_ha.info(f"Retrieving version from file {str(version_file)}")
    s3c = container_client.get_blob_client(version_file)
    try:
        with open('/tmp/version_ctrlha.txt', 'wb') as data:
            s3c.download_blob().readinto(data)

    except Exception as err:
        logger_ha.warning(str(err))
        logger_ha.info("The object does not exist.")
        raise

    if not os.path.exists('/tmp/version_ctrlha.txt'):
        raise AviatrixException("Unable to open version file")

    with open("/tmp/version_ctrlha.txt") as fileh:
        buf = fileh.read()
    logger_ha.info(f"Retrieved version {str(buf)}")

    if not buf:
        raise AviatrixException("  Version file is empty")
    logger_ha.info("Parsing version")

    try:
        ctrl_version = ".".join((buf[12:]).split("."))
    except (KeyboardInterrupt, IndexError, ValueError) as err:
        raise AviatrixException("Could not decode version") from err
    else:
        logger_ha.info(f"Parsed version sucessfully {str(ctrl_version)}")
        logger_ha.warning("")
        return ctrl_version

def is_backup_file_is_recent(backup_file, container_client):
    """ Check if backup file is not older than MAXIMUM_BACKUP_AGE """
    try:
        s3c = container_client.get_blob_client(backup_file)
        try:
            file_obj = s3c.get_blob_properties()
        except Exception as err:
            logger_ha.warning(str(err))
            return False

        age = time.time() - file_obj.last_modified.timestamp()
        if age < MAXIMUM_BACKUP_AGE:
            logger_ha.info("Succesfully validated Backup file age\n")
            return True
        logger_ha.warning(
            f"File age {age} is older than the maximum allowed value of "
            f"{MAXIMUM_BACKUP_AGE}")
        return False
    except Exception as err:
        logger_ha.warning(f"  Checking backup file age failed due to {str(err)}")
        return False

def restore_ctrl_backup(creds, controller_ip, cid, storage, container, blob):
    base_url = f"https://{controller_ip}/v1/api"
    post_data = {"action": "restore_cloudx_config",
                 "cloud_type": "2048",
                 "storage_name": storage,
                 "container_name": container,
                 "file_name": blob,
                 "CID": cid,
                 "arm_application_client_secret": creds['client_secret'],
                 "arm_subscription_id": creds['subscription_id'],
                 "arm_application_endpoint": creds['tenant_id'],
                 "arm_application_client_id": creds['client_id']
                 }
    payload_with_hidden_password = dict(post_data)
    payload_with_hidden_password["CID"] = "********"
    payload_with_hidden_password["arm_application_client_secret"] = "********"
    logger_ha.info(
        f"Trying to restore backup account with data "
        f"{str(json.dumps(obj=payload_with_hidden_password, indent=4))}\n")

    try:
        response = requests.post(
            base_url, data=post_data, timeout=120, verify=False)
    except requests.Timeout:
        logger_ha.info("Restoring backup timed out. "
                     "Please check the controller for updated config.")
        pass
    except requests.exceptions.ConnectionError as err:
        if "Remote end closed connection without response" in str(err):
            logger_ha.info("Server closed the connection while executing "
                         "create account API. Ignoring response")
            output = {"return": True,
                      'reason': 'Warning!! Server closed the connection'}
            time.sleep(INITIAL_SETUP_DELAY)
        else:
            output = {"return": False, "reason": str(err)}
    except Exception as err:
        logger_ha.info(f"An Error has occurred: {str(err)}")
        raise
    else:
        output = response.json()
        logger_ha.info(output)
        return output

def main(req: func.HttpRequest, context: func.Context) -> func.HttpResponse:
    logging.basicConfig(
        format="%(asctime)s aviatrix-azure-function--- %(message)s",
        level=logging.INFO
    )
    logger_ha.info(
        f"Version : {version.VERSION} invocation_id : {context.invocation_id}")
    req_body = req.get_json()
    headers = {"invocation_id": context.invocation_id,
               "alert_status": req_body['data']['status']}
    if not req_body['data']['status'] == 'Activated':
        logger_ha.warning(f"Alert status type: {req_body['data']['status']}")
        return func.HttpResponse(
            "HA failover event is not triggered",
            headers=headers, status_code=501)

    event = {
        "aviatrix_api_version": "v1",
        "aviatrix_api_route": "api",
        "tenant_id": os.environ["avx_tenant_id"],
        "client_id": os.environ["avx_client_id"],
        "vault_uri": os.environ["keyvault_uri"],
        "vault_secret": os.environ["keyvault_secret"],
        "func_client_id": os.environ["func_client_id"],
        "storage_name": os.environ["storage_name"],
        "container_name": os.environ["container_name"],
        "lb_name": os.environ["lb_name"],
        "rg": os.environ["resource_group_name"]
    }

    try:
        function_handler(event)
    except Exception as err:
        logger_ha.exception(f"Error has occurred: {str(err)}")
    else:
        logger_ha.info("Aviatrix Controller has been initialized successfully")
        logger_ha.info("Loading function completed !!")
        return func.HttpResponse(
            "Failover event completed successfully",
            headers=headers, status_code=200)
azure-functions
azure-common==1.1.23
azure-identity==1.7.1
azure-mgmt-compute==23.1.0
azure-mgmt-network==19.3.0
azure-mgmt-resource==20.0.0
azure-storage-blob==12.9.0
azure-keyvault-secrets==4.3.0
msrestazure==0.6.4
requests==2.26.0
retry==0.9.2
urllib3==1.26.7
opencensus-ext-azure

-->

bhagyshricompany commented 1 year ago

Thanks for informing will check and update you.

bhagyshricompany commented 1 year ago

which doc you referring pls share the link

jocortems commented 1 year ago

@bhagyshricompany I am referring to the Azure China Developer Guide - https://learn.microsoft.com/en-us/azure/china/resources-developer-guide#application-insights

Codeless agent/extension based monitoring for Azure App Services is currently not supported. Snapshot Debugger is also not currently available.

jeremydvoss commented 1 year ago

I've successfully initialize Python Azure Functions with that requirements.txt, so I am unable to reproduce the issue. That error message does not come from the extension. So, I think there must be something else going wrong. I would reexamine the assumption that adding this extension package is the only thing changing.

EDIT: I tried to reproduce the issue in the US. So, it's possible that there is some China-specific issue with Functions. I doubt that, but you could open a ticket with the functions team.

jocortems commented 1 year ago

@bhagyshricompany @jeremydvoss, wanted to follow up on this and see if you've had a chance to test this in China.

bhagyshricompany commented 1 year ago

@jeremydvoss pls comment

jeremydvoss commented 1 year ago

"Running pip install -r requirements.txt followed by phyton3.9 func.py directly from shell within the function worker works perfectly fine, the issue only seems to be when deploying using Azure Core tools with func azure functionapp publish avx-controller-functionapp --build remote --python"

Given that our code is not being run and can also be installed successful, it seems that this is an issue on the function's side. Is functions doing something different than "pip install -r requirements.txt"?

cdcadman commented 1 year ago

I am having the same problem in West US. I'm deploying the Azure function from Azure DevOps using this inline script: func azure functionapp publish chuckazfuncpocfaD01. This is the deployment log when I included opencensus-ext-azure:

2023-07-12T08:38:16.7341246Z ##[section]Starting: Deploy Azure Function
2023-07-12T08:38:16.7346236Z ==============================================================================
2023-07-12T08:38:16.7346370Z Task         : Azure CLI
2023-07-12T08:38:16.7346438Z Description  : Run Azure CLI commands against an Azure subscription in a PowerShell Core/Shell script when running on Linux agent or PowerShell/PowerShell Core/Batch script when running on Windows agent.
2023-07-12T08:38:16.7346650Z Version      : 2.223.0
2023-07-12T08:38:16.7346712Z Author       : Microsoft Corporation
2023-07-12T08:38:16.7346785Z Help         : https://docs.microsoft.com/azure/devops/pipelines/tasks/deploy/azure-cli
2023-07-12T08:38:16.7346892Z ==============================================================================
2023-07-12T08:38:17.1238913Z [command]/usr/bin/az --version
2023-07-12T08:38:18.7321003Z WARNING: You have 2 update(s) available. Consider updating your CLI installation with 'az upgrade'
2023-07-12T08:38:18.7321731Z azure-cli                         2.49.0 *
2023-07-12T08:38:18.7323282Z 
2023-07-12T08:38:18.7323635Z core                              2.49.0 *
2023-07-12T08:38:18.7323924Z telemetry                          1.0.8
2023-07-12T08:38:18.7324155Z 
2023-07-12T08:38:18.7372776Z Extensions:
2023-07-12T08:38:18.7373154Z azure-devops                      0.26.0
2023-07-12T08:38:18.7373224Z 
2023-07-12T08:38:18.7373356Z Dependencies:
2023-07-12T08:38:18.7373488Z msal                              1.20.0
2023-07-12T08:38:18.7373701Z azure-mgmt-resource               22.0.0
2023-07-12T08:38:18.7373772Z 
2023-07-12T08:38:18.7373972Z Python location '/opt/az/bin/python3'
2023-07-12T08:38:18.7374203Z Extensions directory '/opt/az/azcliextensions'
2023-07-12T08:38:18.7374301Z 
2023-07-12T08:38:18.7374504Z Python (Linux) 3.10.10 (main, May 19 2023, 08:20:31) [GCC 11.3.0]
2023-07-12T08:38:18.7374626Z 
2023-07-12T08:38:18.7374772Z Legal docs and information: aka.ms/AzureCliLegal
2023-07-12T08:38:18.7374890Z 
2023-07-12T08:38:18.7374934Z 
2023-07-12T08:38:18.7375983Z Setting AZURE_CONFIG_DIR env variable to: /home/vsts/work/_temp/.azclitask
2023-07-12T08:38:18.7376608Z Setting active cloud to: AzureCloud
2023-07-12T08:38:18.7380101Z [command]/usr/bin/az cloud set -n AzureCloud
2023-07-12T08:38:24.4512119Z [command]/usr/bin/pwsh -NoLogo -NoProfile -NonInteractive -ExecutionPolicy Unrestricted -Command . '/home/vsts/work/_temp/azureclitaskscript1689151097108.ps1'
2023-07-12T08:38:28.0422070Z Getting site publishing info...
2023-07-12T08:38:28.0453009Z Creating archive for current directory...
2023-07-12T08:38:28.0484022Z Performing remote build for functions project.
2023-07-12T08:38:29.6488156Z Uploading 7.15 KB []Remote build in progress, please wait...
2023-07-12T08:38:43.3239103Z Updating submodules.
2023-07-12T08:38:43.3239989Z Preparing deployment for commit id '3277beef-3'.
2023-07-12T08:38:43.3240332Z PreDeployment: context.CleanOutputPath False
2023-07-12T08:38:43.3241041Z PreDeployment: context.OutputPath /home/site/wwwroot
2023-07-12T08:38:43.3241378Z Repository path is /tmp/zipdeploy/extracted
2023-07-12T08:38:43.3241664Z Running oryx build...
2023-07-12T08:38:43.3242293Z Command: oryx build /tmp/zipdeploy/extracted -o /tmp/build/expressbuild --platform python --platform-version 3.10.4 -i /tmp/8db82b361ed0273 -p packagedir=.python_packages/lib/site-packages
2023-07-12T08:38:43.3242758Z Operation performed by Microsoft Oryx, https://github.com/Microsoft/Oryx
2023-07-12T08:38:43.3243110Z You can report issues at https://github.com/Microsoft/Oryx/issues
2023-07-12T08:38:43.3243307Z 
2023-07-12T08:38:43.3243639Z Oryx Version: 0.2.20230508.1, Commit: 7fe2bf39b357dd68572b438a85ca50b5ecfb4592, ReleaseTagName: 20230508.1
2023-07-12T08:38:43.3243878Z 
2023-07-12T08:38:43.3244136Z Build Operation ID: dc9a5bd25a4b913e
2023-07-12T08:38:43.3244548Z Repository Commit : 3277beef-3c5a-4fe4-a3cb-cd9349d1b3ce
2023-07-12T08:38:43.3244855Z OS Type           : bullseye
2023-07-12T08:38:43.3245128Z Image Type        : githubactions
2023-07-12T08:38:43.3245298Z 
2023-07-12T08:38:43.3245539Z Detecting platforms...
2023-07-12T08:38:43.3245937Z Platform 'hugo' has been disabled, so skipping detection for it.
2023-07-12T08:38:43.3246250Z Detected following platforms:
2023-07-12T08:38:43.3246503Z   python: 3.10.4
2023-07-12T08:38:43.3246673Z 
2023-07-12T08:38:43.3247012Z Using intermediate directory '/tmp/8db82b361ed0273'.
2023-07-12T08:38:43.3247217Z 
2023-07-12T08:38:43.3247469Z Copying files to the intermediate directory...
2023-07-12T08:38:43.3247749Z Done in 0 sec(s).
2023-07-12T08:38:43.3247903Z 
2023-07-12T08:38:43.3248168Z Source directory     : /tmp/8db82b361ed0273
2023-07-12T08:38:43.3248471Z Destination directory: /tmp/build/expressbuild
2023-07-12T08:38:43.3248652Z 
2023-07-12T08:38:43.3248932Z Python Version: /tmp/oryx/platforms/python/3.10.4/bin/python3.10
2023-07-12T08:38:43.3249261Z Creating directory for command manifest file if it does not exist
2023-07-12T08:38:43.3249573Z Removing existing manifest file
2023-07-12T08:38:43.3249761Z 
2023-07-12T08:38:43.3249989Z Running pip install...
2023-07-12T08:39:16.6856650Z Done in 32 sec(s).
2023-07-12T08:39:16.6857214Z [08:38:44+0000] Collecting azure-functions
2023-07-12T08:39:16.6857593Z [08:38:44+0000]   Using cached azure_functions-1.15.0-py3-none-any.whl (165 kB)
2023-07-12T08:39:16.6857929Z [08:38:44+0000] Collecting opencensus-ext-azure
2023-07-12T08:39:16.6858296Z [08:38:44+0000]   Using cached opencensus_ext_azure-1.1.9-py2.py3-none-any.whl (43 kB)
2023-07-12T08:39:16.6858654Z [08:38:44+0000] Collecting azure-identity<2.0.0,>=1.5.0
2023-07-12T08:39:16.6859026Z [08:38:44+0000]   Using cached azure_identity-1.13.0-py3-none-any.whl (151 kB)
2023-07-12T08:39:16.6859266Z [08:38:45+0000] Collecting requests>=2.19.0
2023-07-12T08:39:16.6859612Z [08:38:45+0000]   Using cached requests-2.31.0-py3-none-any.whl (62 kB)
2023-07-12T08:39:16.6859868Z [08:38:45+0000] Collecting opencensus<1.0.0,>=0.11.2
2023-07-12T08:39:16.6860251Z [08:38:45+0000]   Using cached opencensus-0.11.2-py2.py3-none-any.whl (128 kB)
2023-07-12T08:39:16.6860846Z [08:38:46+0000] Collecting psutil>=5.6.3
2023-07-12T08:39:16.6861369Z [08:38:46+0000]   Using cached psutil-5.9.5-cp36-abi3-manylinux_2_12_x86_64.manylinux2010_x86_64.manylinux_2_17_x86_64.manylinux2014_x86_64.whl (282 kB)
2023-07-12T08:39:16.6861782Z [08:38:46+0000] Collecting azure-core<2.0.0,>=1.12.0
2023-07-12T08:39:16.6862131Z [08:38:46+0000]   Using cached azure_core-1.28.0-py3-none-any.whl (185 kB)
2023-07-12T08:39:16.6862463Z [08:38:47+0000] Collecting typing-extensions>=4.3.0
2023-07-12T08:39:16.6862833Z [08:38:47+0000]   Using cached typing_extensions-4.7.1-py3-none-any.whl (33 kB)
2023-07-12T08:39:16.6863063Z [08:38:47+0000] Collecting six>=1.11.0
2023-07-12T08:39:16.6863401Z [08:38:47+0000]   Using cached six-1.16.0-py2.py3-none-any.whl (11 kB)
2023-07-12T08:39:16.6863648Z [08:38:47+0000] Collecting msal<2.0.0,>=1.20.0
2023-07-12T08:39:16.6863984Z [08:38:47+0000]   Using cached msal-1.22.0-py2.py3-none-any.whl (90 kB)
2023-07-12T08:39:16.6864452Z [08:38:47+0000] Collecting msal-extensions<2.0.0,>=0.3.0
2023-07-12T08:39:16.6864830Z [08:38:47+0000]   Using cached msal_extensions-1.0.0-py2.py3-none-any.whl (19 kB)
2023-07-12T08:39:16.6865075Z [08:38:50+0000] Collecting cryptography>=2.5
2023-07-12T08:39:16.6865474Z [08:38:50+0000]   Using cached cryptography-41.0.2-cp37-abi3-manylinux_2_28_x86_64.whl (4.3 MB)
2023-07-12T08:39:16.6865734Z [08:38:52+0000] Collecting cffi>=1.12
2023-07-12T08:39:16.6866154Z [08:38:52+0000]   Using cached cffi-1.15.1-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (441 kB)
2023-07-12T08:39:16.6866433Z [08:38:52+0000] Collecting pycparser
2023-07-12T08:39:16.6866781Z [08:38:52+0000]   Using cached pycparser-2.21-py2.py3-none-any.whl (118 kB)
2023-07-12T08:39:16.6867025Z [08:38:53+0000] Collecting PyJWT[crypto]<3,>=1.0.0
2023-07-12T08:39:16.6867371Z [08:38:53+0000]   Using cached PyJWT-2.7.0-py3-none-any.whl (22 kB)
2023-07-12T08:39:16.6867624Z [08:38:53+0000] Collecting portalocker<3,>=1.0
2023-07-12T08:39:16.6867985Z [08:38:53+0000]   Using cached portalocker-2.7.0-py2.py3-none-any.whl (15 kB)
2023-07-12T08:39:16.6868312Z [08:38:53+0000] Collecting opencensus-context>=0.1.3
2023-07-12T08:39:16.6868693Z [08:38:53+0000]   Using cached opencensus_context-0.1.3-py2.py3-none-any.whl (5.1 kB)
2023-07-12T08:39:16.6869052Z [08:38:54+0000] Collecting google-api-core<3.0.0,>=1.0.0
2023-07-12T08:39:16.6869410Z [08:38:54+0000]   Using cached google_api_core-2.11.1-py3-none-any.whl (120 kB)
2023-07-12T08:39:16.6869751Z [08:38:57+0000] Collecting protobuf!=3.20.0,!=3.20.1,!=4.21.0,!=4.21.1,!=4.21.2,!=4.21.3,!=4.21.4,!=4.21.5,<5.0.0.dev0,>=3.19.5
2023-07-12T08:39:16.6870217Z [08:38:57+0000]   Using cached protobuf-4.23.4-cp37-abi3-manylinux2014_x86_64.whl (304 kB)
2023-07-12T08:39:16.6870588Z [08:38:57+0000] Collecting googleapis-common-protos<2.0.dev0,>=1.56.2
2023-07-12T08:39:16.6870998Z [08:38:57+0000]   Using cached googleapis_common_protos-1.59.1-py2.py3-none-any.whl (224 kB)
2023-07-12T08:39:16.6871442Z [08:38:58+0000] Collecting google-auth<3.0.dev0,>=2.14.1
2023-07-12T08:39:16.6871808Z [08:38:58+0000]   Using cached google_auth-2.22.0-py2.py3-none-any.whl (181 kB)
2023-07-12T08:39:16.6872106Z [08:38:58+0000] Collecting rsa<5,>=3.1.4
2023-07-12T08:39:16.6872507Z [08:38:58+0000]   Using cached rsa-4.9-py3-none-any.whl (34 kB)
2023-07-12T08:39:16.6872725Z [08:38:59+0000] Collecting urllib3<2.0
2023-07-12T08:39:16.6873129Z [08:38:59+0000]   Using cached urllib3-1.26.16-py2.py3-none-any.whl (143 kB)
2023-07-12T08:39:16.6873437Z [08:38:59+0000] Collecting cachetools<6.0,>=2.0.0
2023-07-12T08:39:16.6873777Z [08:38:59+0000]   Using cached cachetools-5.3.1-py3-none-any.whl (9.3 kB)
2023-07-12T08:39:16.6874153Z [08:38:59+0000] Collecting pyasn1-modules>=0.2.1
2023-07-12T08:39:16.6874574Z [08:38:59+0000]   Using cached pyasn1_modules-0.3.0-py2.py3-none-any.whl (181 kB)
2023-07-12T08:39:16.6874937Z [08:39:00+0000] Collecting pyasn1<0.6.0,>=0.4.6
2023-07-12T08:39:16.6875406Z [08:39:00+0000]   Using cached pyasn1-0.5.0-py2.py3-none-any.whl (83 kB)
2023-07-12T08:39:16.6875733Z [08:39:00+0000] Collecting certifi>=2017.4.17
2023-07-12T08:39:16.6876032Z [08:39:00+0000]   Using cached certifi-2023.5.7-py3-none-any.whl (156 kB)
2023-07-12T08:39:16.6876373Z [08:39:01+0000] Collecting charset-normalizer<4,>=2
2023-07-12T08:39:16.6876818Z [08:39:01+0000]   Using cached charset_normalizer-3.2.0-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (201 kB)
2023-07-12T08:39:16.6877063Z [08:39:01+0000] Collecting idna<4,>=2.5
2023-07-12T08:39:16.6877622Z [08:39:01+0000]   Using cached idna-3.4-py3-none-any.whl (61 kB)
2023-07-12T08:39:16.6878528Z [08:39:03+0000] Installing collected packages: pycparser, cffi, urllib3, PyJWT, pyasn1, idna, cryptography, charset-normalizer, certifi, six, rsa, requests, pyasn1-modules, protobuf, cachetools, typing-extensions, portalocker, msal, googleapis-common-protos, google-auth, opencensus-context, msal-extensions, google-api-core, azure-core, psutil, opencensus, azure-identity, opencensus-ext-azure, azure-functions
2023-07-12T08:39:20.9948748Z [08:39:13+0000] Successfully installed PyJWT-2.7.0 azure-core-1.28.0 azure-functions-1.15.0 azure-identity-1.13.0 cachetools-5.3.1 certifi-2023.5.7 cffi-1.15.1 charset-normalizer-3.2.0 cryptography-41.0.2 google-api-core-2.11.1 google-auth-2.22.0 googleapis-common-protos-1.59.1 idna-3.4 msal-1.22.0 msal-extensions-1.0.0 opencensus-0.11.2 opencensus-context-0.1.3 opencensus-ext-azure-1.1.9 portalocker-2.7.0 protobuf-4.23.4 psutil-5.9.5 pyasn1-0.5.0 pyasn1-modules-0.3.0 pycparser-2.21 requests-2.31.0 rsa-4.9 six-1.16.0 typing-extensions-4.7.1 urllib3-1.26.16
2023-07-12T08:39:20.9950074Z WARNING: You are using pip version 21.2.4; however, version 23.1.2 is available.
2023-07-12T08:39:20.9950795Z You should consider upgrading via the '/tmp/oryx/platforms/python/3.10.4/bin/python3.10 -m pip install --upgrade pip' command.
2023-07-12T08:39:20.9998647Z Not a vso image, so not writing build commands
2023-07-12T08:39:20.9999565Z Preparing output...
2023-07-12T08:39:20.9999717Z 
2023-07-12T08:39:21.0000263Z Copying files to destination directory '/tmp/build/expressbuild'...
2023-07-12T08:39:21.0000587Z Done in 3 sec(s).
2023-07-12T08:39:21.0000660Z 
2023-07-12T08:39:21.0000891Z Removing existing manifest file
2023-07-12T08:39:21.0001073Z Creating a manifest file...
2023-07-12T08:39:21.0001302Z Manifest file created.
2023-07-12T08:39:21.0001543Z Copying .ostype to manifest output directory.
2023-07-12T08:39:21.0001641Z 
2023-07-12T08:39:21.0001776Z Done in 36 sec(s).
2023-07-12T08:39:21.0002003Z Writing the artifacts to a Zip file
2023-07-12T08:39:24.3539530Z Running post deployment command(s)...
2023-07-12T08:39:24.3539695Z 
2023-07-12T08:39:24.3539858Z Generating summary of Oryx build
2023-07-12T08:39:24.3540537Z Deployment Log file does not exist in /tmp/oryx-build.log
2023-07-12T08:39:24.3540947Z The logfile at /tmp/oryx-build.log is empty. Unable to fetch the summary of build
2023-07-12T08:39:24.3541211Z Triggering recycle (preview mode disabled).
2023-07-12T08:39:24.3541685Z Deployment successful. deployer = Push-Deployer deploymentPath = Functions App ZipDeploy. Extract zip. Remote build.
2023-07-12T08:39:27.3552458Z Remote build succeeded!
2023-07-12T08:39:28.4167140Z [command]/usr/bin/az account clear
2023-07-12T08:39:28.9696123Z ##[section]Finishing: Deploy Azure Function

This is from the default docker log:

2023-07-12T09:57:00.484247363Z Starting OpenBSD Secure Shell server: sshd.
2023-07-12T09:59:18.251969897Z Hosting environment: Production
2023-07-12T09:59:18.268409880Z Content root path: /azure-functions-host
2023-07-12T09:59:18.268892912Z Now listening on: http://[::]:80
2023-07-12T09:59:18.268907313Z Application started. Press Ctrl+C to shut down.

Here is the docker log:

2023-07-12T09:57:02.718Z INFO  - Initiating warmup request to container chuckazfuncpocfad01_1_451959e8 for site chuckazfuncpocfad01
2023-07-12T09:57:34.405Z INFO  - Waiting for response to warmup request for container chuckazfuncpocfad01_1_451959e8. Elapsed time = 31.6870666 sec
2023-07-12T09:57:51.337Z INFO  - Waiting for response to warmup request for container chuckazfuncpocfad01_1_451959e8. Elapsed time = 48.6194851 sec
2023-07-12T09:58:14.319Z INFO  - Waiting for response to warmup request for container chuckazfuncpocfad01_1_451959e8. Elapsed time = 71.6007311 sec
2023-07-12T09:58:31.684Z INFO  - Waiting for response to warmup request for container chuckazfuncpocfad01_1_451959e8. Elapsed time = 88.9662995 sec
2023-07-12T09:58:48.246Z INFO  - Waiting for response to warmup request for container chuckazfuncpocfad01_1_451959e8. Elapsed time = 105.5278684 sec
2023-07-12T09:59:05.691Z INFO  - Waiting for response to warmup request for container chuckazfuncpocfad01_1_451959e8. Elapsed time = 122.9727993 sec
2023-07-12T09:59:19.051Z ERROR - Container chuckazfuncpocfad01_1_451959e8 for site chuckazfuncpocfad01 has exited, failing site start
2023-07-12T09:59:19.070Z ERROR - Container chuckazfuncpocfad01_1_451959e8 didn't respond to HTTP pings on port: 80, failing site start. See container logs for debugging.
2023-07-12T09:59:19.073Z INFO  - Stopping site chuckazfuncpocfad01 because it failed during startup.

I wasn't able to retrieve any container logs.

bhagyshricompany commented 1 year ago

please create Support request on azure portal for this.

microsoft-github-policy-service[bot] commented 1 year ago

This issue has been automatically marked as stale because it has been marked as requiring author feedback but has not had any activity for 4 days. It will be closed if no further activity occurs within 3 days of this comment.

cdcadman commented 1 year ago

When I started to create a support request, I was directed to an error message: TypeError: Descriptors cannot not be created directly that was being generated somewhere in the function app. This led me to the following stackoverflow article: https://stackoverflow.com/questions/72441758/typeerror-descriptors-cannot-not-be-created-directly. I added the configuration setting PROTOCOL_BUFFERS_PYTHON_IMPLEMENTATION=python, redeployed the function, and now I can trigger the function, even when opencensus-ext-azure is installed. So my issue is fixed.

microsoft-github-policy-service[bot] commented 1 year ago

This issue has been automatically marked as stale because it has been marked as requiring author feedback but has not had any activity for 4 days. It will be closed if no further activity occurs within 3 days of this comment.