Azure / Azure/azure-functions-host

A lot of traces and dependencies items with operation_name MessageRelayOutbox in Application Insight

Open
#7,875 5 comments 0 reactions 2 assignees Claimed by @v-bbalaiagar View on GitHub
needs-investigation
Dominant language
C#
Stars
2k
Forks
482
Avg merge
2d 12h
Merged PRs (30d)
38

Description

Environnent Information :
- FUNCTIONS_EXTENSION_VERSION : ~3
- FUNCTIONS_WORKER_RUNTIME : dotnet
- Function App version:
- Invocation ID: cd561f4e-dae7-4ead-976d-9eb7e7fca057
- Region: West Europe
- Development Language: C#

I am seeing a lot of traces and dependencies items with operation_name MessageRelayOutbox in Application Insight. For example in the weekend only a TimerTrigger is running purging the durable functions Instance and History table like:

```
private async Task ClearItemsAsync(IDurableClient client, DateTime fromDate, DateTime toDate, IEnumerable runtimeStatus)
{
this.logger.LogInformation($"Purging history and instance table for {runtimeStatus} items created between {fromDate:yyyy-MM-ddTHH:mm:ssZ} and {toDate:yyyy-MM-ddTHH:mm:ssZ}.");

PurgeHistoryResult purgeResult = await client.PurgeInstanceHistoryAsync(
fromDate,
toDate,
runtimeStatus).ConfigureAwait(true); // ConfigureAwait should be set to true in Azure functions.

this.logger.LogInformation($"Purged {purgeResult.InstancesDeleted} instances.");
}
```

The TimerTrigger contains a schedule expression like: “0 0 * * * *” (so it’s running every hour).

When I perform the following query in Application Insight:
```
dependencies
| where timestamp > datetime("2021-11-21T00:00:00.600Z") and timestamp < datetime("2021-11-21T23:00:00.600Z")
| summarize sum(_BilledSize) by operation_Name
```
I get the following result:
- MessageRelayOutbox: 26,545,680
- PurgeHistoryTimer: 29,716
Meaning a lot MessageRelayOutbox items, which feels strange to me.

The Timer function looks like:

```
private const string EveryHour = "0 0 * * * *";
private readonly ILogger logger;

///
/// Initializes a new instance of the class.
///
/// an instance of .
public PurgeHistoryTimer(ILogger logger)
{
this.logger = logger;
}

///
/// Called when the timer expires.
///
/// an instance of .
/// an instance of .
/// A representing the asynchronous operation.
[FunctionName(nameof(PurgeHistoryTimer))]
public async Task RunAsync(
[TimerTrigger(EveryHour)] TimerInfo timer,
[DurableClient] IDurableClient client)
{
timer.AssertIsNotNull(nameof(timer));
client.AssertIsNotNull(nameof(client));

await this.ClearCompletedItems(client).ConfigureAwait(false);

await this.ClearFailedItems(client).ConfigureAwait(false);
}
```

It looks like all the traces and dependencies are related to managed identity. Example messages returned from App Insights:
Columns
timestamp [UTC]
id
target
type
name
data
success
resultCode
duration
performanceBucket
itemType
customDimensions
operation_Name
operation_Id
operation_ParentId
client_Type
client_IP
cloud_RoleName
cloud_RoleInstance
appId

Example1
`11/22/2021, 10:55:39.997 AM 7dc2bb6e9d9b4843 127.0.0.1:41967 HTTP GET /MSI/token/ http://127.0.0.1:41967/MSI/token/?api-version=2017-09-01&resource=546d59fd-bd41-41a3-b700-780c50fc0162&clientid=a6b947bd-****-****-****-************ True 200 2.893 <250ms dependency {"Category":"Function.MessageRelayOutbox","ProcessId":"860","HostInstanceId":"c09a9f94-cbd1-4e79-a9b6-4f34d67e2063","ClientRequestId":"adb051a9-9627-4e14-bcb7-dfa65647020f","LogLevel":"Information","InvocationId":"cd561f4e-dae7-4ead-976d-9eb7e7fca057"} MessageRelayOutbox dc3d7afd221e0248aba00e4005f50555 2ce0cced6a2ff044 PC 0.0.0.0 func-XYZ-configurationmessagerelayoutbox-p01 dbd679437e659890e5b5d2b38d5d02495bbfed5e20ecb7205e78c1eca85ef87b d2748353-e09c-4eea-a08f-364d9b731086 `

Example2
`11/22/2021, 10:55:39.997 AM 1f90608cd0320340 ManagedIdentityCredential.GetToken InProc | Microsoft.AAD ManagedIdentityCredential.GetToken True 3.244 <250ms dependency {"Category":"Function.MessageRelayOutbox","ProcessId":"860","HostInstanceId":"c09a9f94-cbd1-4e79-a9b6-4f34d67e2063","LogLevel":"Information","InvocationId":"cd561f4e-dae7-4ead-976d-9eb7e7fca057"} MessageRelayOutbox dc3d7afd221e0248aba00e4005f50555 2ce0cced6a2ff044 PC 0.0.0.0 func-XYZ-configurationmessagerelayoutbox-p01 dbd679437e659890e5b5d2b38d5d02495bbfed5e20ecb7205e78c1eca85ef87b d2748353-e09c-4eea-a08f-364d9b731086 `

Example3
`11/22/2021, 10:55:39.997 AM 2ce0cced6a2ff044 DefaultAzureCredential.GetToken InProc | Microsoft.AAD DefaultAzureCredential.GetToken True 3.491 <250ms dependency {"Category":"Function.MessageRelayOutbox","ProcessId":"860","HostInstanceId":"c09a9f94-cbd1-4e79-a9b6-4f34d67e2063","LogLevel":"Information","InvocationId":"cd561f4e-dae7-4ead-976d-9eb7e7fca057"} MessageRelayOutbox dc3d7afd221e0248aba00e4005f50555 72d4a9c8e55e384e PC 0.0.0.0 func-XYZ-configurationmessagerelayoutbox-p01 dbd679437e659890e5b5d2b38d5d02495bbfed5e20ecb7205e78c1eca85ef87b d2748353-e09c-4eea-a08f-364d9b731086 `

Example4
`11/22/2021, 10:55:49.995 AM ccae72e5bcdade4a 127.0.0.1:41967 HTTP GET /MSI/token/ http://127.0.0.1:41967/MSI/token/?api-version=2017-09-01&resource=546d59fd-bd41-41a3-b700-780c50fc0162&clientid=a6b947bd-****-****-****-************ True 200 3.14 <250ms dependency {"Category":"Function.MessageRelayOutbox","ProcessId":"860","HostInstanceId":"c09a9f94-cbd1-4e79-a9b6-4f34d67e2063","ClientRequestId":"ddf9c4a7-7d26-495c-b2f4-33c221e3d589","LogLevel":"Information","InvocationId":"c381a384-def2-48e0-bbb2-67fad2dcf4ee"} MessageRelayOutbox 1b392970b56f914b9cc46f96f9fda2af 93f06c33f27d734a PC 0.0.0.0 func-XYZ-configurationmessagerelayoutbox-p01 dbd679437e659890e5b5d2b38d5d02495bbfed5e20ecb7205e78c1eca85ef87b d2748353-e09c-4eea-a08f-364d9b731086 `

Example5
`11/22/2021, 10:55:49.995 AM 9fcac7f61a011a42 ManagedIdentityCredential.GetToken InProc | Microsoft.AAD ManagedIdentityCredential.GetToken True 3.528 <250ms dependency {"Category":"Function.MessageRelayOutbox","ProcessId":"860","HostInstanceId":"c09a9f94-cbd1-4e79-a9b6-4f34d67e2063","LogLevel":"Information","InvocationId":"c381a384-def2-48e0-bbb2-67fad2dcf4ee"} MessageRelayOutbox 1b392970b56f914b9cc46f96f9fda2af 93f06c33f27d734a PC 0.0.0.0 func-XYZ-configurationmessagerelayoutbox-p01 dbd679437e659890e5b5d2b38d5d02495bbfed5e20ecb7205e78c1eca85ef87b d2748353-e09c-4eea-a08f-364d9b731086 `

Question: is amount of MessageRelayOutbox traces and dependencies items as expected or is something wrong?expected?

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.