Open M0ns1gn0r opened 4 years ago
Able to repro the Issue.
@gzuber can you please look into this further
cc @pragnagopa, @mhoeger
As mentioned in the issue, there are duplicate exceptions being created in the logs. I have further dug deep into all the possible logs. Below are my findings:
Repro Steps: Same as mentioned in the issue
Visual Studio- Debug Window: [2020-12-11T17:52:48.565Z] Executing 'Function1' (Reason='This function was programmatically called via the host APIs.', Id=e013a8b7-c377-4de3-ab08-e6c978c35c0b) [2020-12-11T17:52:48.590Z] C# HTTP trigger function processed a request. [2020-12-11T17:52:48.840Z] Executed 'Function1' (Failed, Id=e013a8b7-c377-4de3-ab08-e6c978c35c0b, Duration=274ms) [2020-12-11T17:52:48.841Z] System.Private.CoreLib: Exception while executing function: Function1. 6564-2: Test exception
Visual Studio- Application Insights Search:
After publishing the App, the same is the case with Application insights in portal. There are duplicate logs but coming from Function and host.
**Custom properties:
First Occurrence :**
HostInstanceId | 24996f33-1de8-4a3a-a3ef-2b7af722633b |
---|---|
ProcessId | 1028 |
LogLevel | Error |
Category | Host.Results |
InvocationId | e34a4d70-5200-469a-9e59-75f32aff23a9 |
prop__TriggerReason | This function was programmatically called via the host APIs. |
prop__InvocationId | e34a4d70-5200-469a-9e59-75f32aff23a9 |
prop__StartTime | 2020-12-11T19:03:21.4830000Z |
prop__Succeeded | FALSE |
prop__Duration | 00:00.3 |
prop__FullName | Function1 |
prop__EndTime | 2020-12-11T19:03:21.7590000Z |
prop__Name | Function1 |
Second occurrence:
FormattedMessage | Executed 'Function1' (Failed, Id=e34a4d70-5200-469a-9e59-75f32aff23a9, Duration=3ms) |
---|---|
HostInstanceId | 24996f33-1de8-4a3a-a3ef-2b7af722633b |
prop__{OriginalFormat} | Executed '{functionName}' ({status}, Id={invocationId}, Duration={executionDuration}ms) |
ProcessId | 1028 |
LogLevel | Error |
Category | Function.Function1 |
InvocationId | e34a4d70-5200-469a-9e59-75f32aff23a9 |
prop__executionDuration | 3 |
EventName | FunctionCompleted |
prop__invocationId | e34a4d70-5200-469a-9e59-75f32aff23a9 |
prop__functionName | Function1 |
EventId | 3 |
prop__status | Failed |
However, Kusto logs are producing only one log per time stamp. No duplicate logs produced in Kusto
Kusto Logs:
1. First run
TimeStamp: : 2020-12-11 19:02:57.2747192
Invocation ID: e34a4d70-5200-469a-9e59-75f32aff23a9
2. Second run:
TimeStamp: 2020-12-11 19:03:33.3249734
Invocation ID : d0ec5e3d-0540-4352-9b4f-b6455e603a1d
App name: 6564-2
Tenant : waws-prod-sn1-171
Role instance: dw0SmallDedicatedWebWorkerRole_IN_hr0HostRole-4-VM-1 2
Details: Executed 'Function1' (Failed, Id=584b5d01-0d63-4841-be2d-d316a290686e, Duration=191ms) Microsoft.Azure.WebJobs.Host.FunctionInvocationException : Exception while executing function: Function1 ---> System.ApplicationException : Test exception.
This is still a problem
This repros for a Python function app on Linux as well.
Python: 3.10 Functions runtime: 4.24.4.4
Function code:
import azure.functions as func
import logging
app = func.FunctionApp(http_auth_level=func.AuthLevel.FUNCTION)
@app.route(route="http_trigger")
def http_trigger(req: func.HttpRequest) -> func.HttpResponse:
logging.info('Python HTTP trigger function processed a request.')
raise Exception("test exception")
There are 2 records in the invocation traces with identical content except for the timestamp:
Log analytics query in the portal shows 2 instances of the failure for the same operation/invocation:
Does anyone know why this is happening? I have the same problem: only exceptions are being duplicated, the rest works fine.
We are still seeing this issue in the latest NET8 Isolated Process logs. Should this be labelled as need triage again?
When a function throws an exception, that exception is shown once in the console but is logged twice to AppInsights (testing that locally in Visual Studio) with different categories: Host.Results and Function.Function1.
Investigative information
Azure Functions Core Tools (3.0.2798 Commit hash: d9d99872a51c04b1c2783198b1ee1104da6b064f) Function Runtime Version: 3.0.14191.0
Repro steps
"APPINSIGHTS_INSTRUMENTATIONKEY": "local"
tolocal.settings.json
.ApplicationInsights.config
in the root folder.Expected behavior
After I perform step 5, I see only one exception message both in the console window and in the
Application Insights Search
window.Actual behavior
I see two identical exceptions in the
Application Insights Search
window with different categories: