4

I have spent a while trying to RequestTelemetry to work. It did when I was first playing around with it, but then oddly just stopped working whenever an exception is thrown. I have read documentation using Application Insights for custom events and metrics as well as Custom Operations Tracking and tried to add all of the best practices to see if I could get the result to show up again. I'm using .NET Core 3.1 and Microsoft.ApplicationInsights.AspNetCore 2.14.0.

Setup for the Webapp looks like this in Startup.cs

services.AddApplicationInsightsTelemetry(new ApplicationInsightsServiceOptions { 
    EnableAdaptiveSampling = false
}); 

I have the telemetry inside of a Controller Post Action. I realize that Application Insights is already tracking it the post action, but I wanted to see if I could track the inner method. This is the code in my controller:


public MyController(IMyService myService, TelemetryClient telemetryClient, ILogger<MyController> logger) {
    _myService = myService;
    _telemetryClient = telemetryClient;
    _logger = logger;
}

[HttpPost]
[ProducesResponseType(StatusCodes.Status204NoContent)]
[ProducesResponseType(StatusCodes.Status400BadRequest)]
[ProducesResponseType(StatusCodes.Status401Unauthorized)]
public async Task<IActionResult> PostAsync([FromBody] MyModel model) {
    using var scope = _logger.BeginScope(new Dictionary<string, object> {
        { $"{nameof(PostAsync)}.Scope", Guid.NewGuid() },
        { nameof(model.Name), model.Name }
    });

    model.AuthenticatedUserId = User.GetUserIdFromClaims();

    var requestTelemetry = new RequestTelemetry { Name = nameof( _myService.MyFunctionAsync) };
    var operation = _telemetryClient.StartOperation(requestTelemetry);
    operation.Telemetry.Properties.Add("User", model.AuthenticatedUserId);

    try {
        await _myService.MyFunctionAsync(model).ConfigureAwait(false); // <-- throws exception
        operation.Telemetry.Success = true;
        return NoContent();
    } catch (Exception e) {
        operation.Telemetry.Success = false;
        throw;
    } finally {
        _telemetryClient.StopOperation(operation);
    }
}

I can see in the Visual Studio console output that the code executes, as I get the following log, but it never shows up in the Application Insights Requests.

Application Insights Telemetry: {
  "name": "AppRequests",
  "time": "2020-06-21T14:29:08.7469588Z",
  "iKey": "XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXXXXX",
  "tags": {
    "ai.application.ver": "1.0.0.0",
    "ai.cloud.roleInstance": "DESKTOP-K74PNCU",
    "ai.operation.id": "0443259d660125498cf28f8f7a275dab",
    "ai.operation.parentId": "1dea6f9b27220c4c",
    "ai.operation.name": "POST EventEmitter/Post",
    "ai.location.ip": "::1",
    "ai.internal.sdkVersion": "dotnetc:2.14.0-17971",
    "ai.internal.nodeName": "DESKTOP-K74PNCU"
  },
  "data": {
    "baseType": "RequestData",
    "baseData": {
      "ver": 2,
      "id": "2b7900eedfb7c34d",
      "name": "MyFunctionAsync",
      "duration": "00:00:00.3766937",
      "success": false,
      "properties": {
        "DeveloperMode": "true",
        "User": "pobl-dev",
        "_MS.ProcessedByMetricExtractors": "(Name:'Requests', Ver:'1.1')",
        "AspNetCoreEnvironment": "Development"
      }
    }
  }
}
scottrudy
  • 1,633
  • 1
  • 14
  • 24
  • and how do you initialize the _telemetryClient? and when initialized the _telemetryClient, did you use another instrumentation key? – Ivan Glasenberg Jun 22 '20 at 06:30
  • and is the `throw` is a must here in catch block? – Ivan Glasenberg Jun 22 '20 at 09:40
  • @IvanYang I have updated the code with the constructor so you can see the initialization. The throw is necessary so that the global error handler catches the error, as opposed to tracking the exception in the controller. – scottrudy Jun 22 '20 at 15:08

2 Answers2

9

There is a simple solution, but I'm not sure of why it's necessary, due to either a lack in documentation or a bug. I found once a responseCode was provided everything works fine. There is a default responseCode of 200 which shows up on a successful call. Once I set the value on a failure everything worked fine.


public MyController(IMyService myService, TelemetryClient telemetryClient, ILogger<MyController> logger) {
    _myService = myService;
    _telemetryClient = telemetryClient;
    _logger = logger;
}

[HttpPost]
[ProducesResponseType(StatusCodes.Status204NoContent)]
[ProducesResponseType(StatusCodes.Status400BadRequest)]
[ProducesResponseType(StatusCodes.Status401Unauthorized)]
public async Task<IActionResult> PostAsync([FromBody] MyModel model) {
    using var scope = _logger.BeginScope(new Dictionary<string, object> {
        { $"{nameof(PostAsync)}.Scope", Guid.NewGuid() },
        { nameof(model.Name), model.Name }
    });

    model.AuthenticatedUserId = User.GetUserIdFromClaims();

    var requestTelemetry = new RequestTelemetry { Name = nameof( _myService.MyFunctionAsync) };
    var operation = _telemetryClient.StartOperation(requestTelemetry);
    operation.Telemetry.Properties.Add("User", model.AuthenticatedUserId);

    try {
        await _myService.MyFunctionAsync(model).ConfigureAwait(false); // <-- throws exception
        operation.Telemetry.Success = true;
        operation.Telemetry.ResponseCode = "Roses";
        return NoContent();
    } catch (Exception e) {
        operation.Telemetry.Success = false;
        operation.Telemetry.ResponseCode = "Funky"; // <-- seems to be required on a failure
        throw;
    } finally {
        _telemetryClient.StopOperation(operation);
    }
}
scottrudy
  • 1,633
  • 1
  • 14
  • 24
  • Actually, you don't need to set the responseCode(it's not a good practice to change the response code). Please try my solution:). – Ivan Glasenberg Jun 23 '20 at 01:30
  • @IvanYang what do you mean it's not a good practice? Can you point to a reference document that states that? I see examples of doing that in both Microsoft Docs links I provided in the question. – scottrudy Jun 24 '20 at 19:02
  • https://github.com/microsoft/ApplicationInsights-Home/blob/master/EndpointSpecs/Schemas/Bond/RequestData.bond#L22 Maybe ResultCode is a required field and without it, backend rejects the item. This could be validating by running Fiddler and observe the backend response. – cijothomas Jul 12 '20 at 15:56
  • @IvanYang what's your solution? – gukoff Jun 23 '21 at 14:10
  • Thank you, thank you, thank you, thank you. Our workers now reported in a standardised way. This is what stackoverflow is for!! – penderi Oct 13 '21 at 09:22
2

This is to add some context to the accepted answer if you're curious:

Here's the source code for RequestTelemetry

When it prepares the data to send to Azure servers it explicitly elects NOT to set a default response code unless success == true in which case the default is 200.

// Required fields
if (!this.Success.HasValue)
{
    this.Success = true;
}

if (string.IsNullOrEmpty(this.ResponseCode))
{
    this.ResponseCode = this.Success.Value ? "200" : string.Empty;
}     

If you run a simple Kusto query on the logs:

union requests | where timestamp > ago(1hr) | where customDimensions["CustomOperationCategory"] in ("Identity") | take 100

You'll only see unsuccessful results where you did set a status code:

enter image description here

I don't know if something ever changed, but Microsoft's examples sometimes do the same.

Simon_Weaver
  • 140,023
  • 84
  • 646
  • 689