Skip to content

Add ILoggerProvider to capture error logs as APM logs#1135

Merged
gregkalapos merged 20 commits intoelastic:masterfrom
gregkalapos:ErrorLogsAsApmErrors
Feb 16, 2021
Merged

Add ILoggerProvider to capture error logs as APM logs#1135
gregkalapos merged 20 commits intoelastic:masterfrom
gregkalapos:ErrorLogsAsApmErrors

Conversation

@gregkalapos
Copy link
Copy Markdown
Contributor

@gregkalapos gregkalapos commented Jan 14, 2021

Closes #894

Adding an ILoggerProvider which captures logs on error level as APM Errors. By using the IHostBuilder extension method to enable the agent, we automatically turn on this feature and capture all error logs as APM errors.

E.g.

_logger.LogError("This is a sample error log message, with a sample value: {intParam}", 42 );

(where _logger is a plain Microsoft.Extensions.Loggiong.ILogger) will show up as a normal error:
image

image

This PR also extends the public API

Capturing Exceptions and Errors directly on ITracer

agent.Tracer.CaptureError("foo", "bar");
try
{
   throw new Exception("foo");
}
catch (Exception e)
{
   agent.Tracer.CaptureException(e);
}

In case there is no current active span or transaction the error will show up on the UI, but won't be correlated to any transaction/span.

And also added log capturing as part of the public API:

Directly on tracer:

var errorLog = new ErrorLog("LogMessage")
{
	Level = "error",
	ParamMessage = "42"
};

agent.Tracer.CaptureErrorLog(errorLog);

On a span:

var errorLog = new ErrorLog("foo")
{
	Level = "error",
	ParamMessage = "42"
};

agent.Tracer.CaptureTransaction("foo", "bar", t =>
{
	t.CaptureSpan("foo", "bar", s =>
	{
		s.CaptureErrorLog(errorLog);
	});
});

On a transaction:

var errorLog = new ErrorLog("foo")
{
	Level = "error",
	ParamMessage = "42"
};

agent.Tracer.CaptureTransaction("foo", "bar", t =>
{
	t.CaptureErrorLog(errorLog);
});

@gregkalapos gregkalapos self-assigned this Jan 14, 2021
@gregkalapos gregkalapos marked this pull request as draft January 14, 2021 19:51
@gregkalapos gregkalapos marked this pull request as ready for review January 19, 2021 20:00
@ghost
Copy link
Copy Markdown

ghost commented Jan 19, 2021

❕ Build Aborted

There is a new build on-going so the previous on-going builds have been aborted.

the below badges are clickable and redirect to their specific view in the CI or DOCS
Pipeline View Test View Changes Artifacts

Expand to view the summary

Build stats

  • Build Cause: Started by user Gergely Kalapos

  • Reason: Aborted from #29

  • Start Time: 2021-02-16T20:31:20.146+0000

  • Duration: 56 min 34 sec

  • Commit: dd29154

Test stats 🧪

Test Results
Failed 1
Passed 18125
Skipped 76
Total 18202

Trends 🧪

Image of Build Times

Image of Tests

Test errors 1

Expand to view the tests failures

Initializing / Parallel / Linux / Test / CentralConfigFetcherTests.Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests.Should_Update_Logger_That_Is_ILogLevelSwitchable – Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests
    Expand to view the error details

     Expected testLogger.LogLevelSwitch.Level to be Error, but found Trace. 
    

    Expand to view the stacktrace

     Expected testLogger.LogLevelSwitch.Level to be Error, but found Trace.
    Stack Trace:
       at FluentAssertions.Execution.XUnit2TestFramework.Throw(String message) in C:\projects\fluentassertions-vf06b\Src\FluentAssertions\Execution\XUnit2TestFramework.cs:line 32
       at FluentAssertions.Execution.AssertionScope.FailWith(Func`1 failReasonFunc) in C:\projects\fluentassertions-vf06b\Src\FluentAssertions\Execution\AssertionScope.cs:line 181
       at FluentAssertions.Primitives.ObjectAssertions.Be(Object expected, String because, Object[] becauseArgs) in C:\projects\fluentassertions-vf06b\Src\FluentAssertions\Primitives\ObjectAssertions.cs:line 38
       at Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests.Should_Update_Logger_That_Is_ILogLevelSwitchable() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1135/apm-agent-dotnet/test/Elastic.Apm.Tests/BackendCommTests/CentralConfig/CentralConfigFetcherTests.cs:line 78
    Standard Output:
        Elastic APM .NET Tests> 229> Xunit> [2021-02-16 20:51:05.580 +00:00][Info] - {LoggingTestBase} Starting test: Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests.Should_Update_Logger_That_Is_ILogLevelSwitchable...
        Elastic APM .NET Tests> 229> Xunit> [2021-02-16 20:51:25.953 +00:00][Info] - {LoggingTestBase} Finished test: Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests.Should_Update_Logger_That_Is_ILogLevelSwitchable 
    

Steps errors 1

Expand to view the steps failures

Build
  • Took 1 min 32 sec . View more details on here
  • Description: .ci/windows/dotnet.bat

Log output

Expand to view the last 100 lines of log output

[2021-02-16T21:26:39.301Z]       Executing action method Elastic.Apm.Tests.MockApmServer.Controllers.IntakeV2EventsController.Post (Elastic.Apm.Tests.MockApmServer) - Validation state: Valid
[2021-02-16T21:26:39.301Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
[2021-02-16T21:26:39.301Z]       Executed action method Elastic.Apm.Tests.MockApmServer.Controllers.IntakeV2EventsController.Post (Elastic.Apm.Tests.MockApmServer), returned result Microsoft.AspNetCore.Mvc.OkObjectResult in 2.915ms.
[2021-02-16T21:26:39.301Z] info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
[2021-02-16T21:26:39.301Z]       Executing ObjectResult, writing value of type 'System.String'.
[2021-02-16T21:26:39.301Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
[2021-02-16T21:26:39.301Z]       Executed action Elastic.Apm.Tests.MockApmServer.Controllers.IntakeV2EventsController.Post (Elastic.Apm.Tests.MockApmServer) in 3.2272ms
[2021-02-16T21:26:39.301Z] info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
[2021-02-16T21:26:39.301Z]       Request finished in 3.555ms 200 text/plain; charset=utf-8
[2021-02-16T21:26:39.455Z] Sending interrupt signal to process
[2021-02-16T21:26:39.888Z] info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
[2021-02-16T21:26:39.888Z]       Request starting HTTP/1.1 GET http://localhost:23563/config/v1/agents?service.name=AspNetFullFramework_Tests_CentralConfigTests-CustomServiceName&service.environment=AspNetFullFramework_Tests_CentralConfigTests-CustomEnvironment  
[2021-02-16T21:26:39.888Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[3]
[2021-02-16T21:26:39.888Z]       Route matched with {action = "Get", controller = "AgentsConfig"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Get() on controller Elastic.Apm.Tests.MockApmServer.Controllers.AgentsConfigController (Elastic.Apm.Tests.MockApmServer).
[2021-02-16T21:26:39.888Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
[2021-02-16T21:26:39.888Z]       Executing action method Elastic.Apm.Tests.MockApmServer.Controllers.AgentsConfigController.Get (Elastic.Apm.Tests.MockApmServer) - Validation state: Valid
[2021-02-16T21:26:39.889Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
[2021-02-16T21:26:39.889Z]       Executed action method Elastic.Apm.Tests.MockApmServer.Controllers.AgentsConfigController.Get (Elastic.Apm.Tests.MockApmServer), returned result Microsoft.AspNetCore.Mvc.ObjectResult in 0.1714ms.
[2021-02-16T21:26:39.889Z] info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
[2021-02-16T21:26:39.889Z]       Executing ObjectResult, writing value of type 'System.String'.
[2021-02-16T21:26:39.889Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
[2021-02-16T21:26:39.889Z]       Executed action Elastic.Apm.Tests.MockApmServer.Controllers.AgentsConfigController.Get (Elastic.Apm.Tests.MockApmServer) in 0.4725ms
[2021-02-16T21:26:39.889Z] info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
[2021-02-16T21:26:39.889Z]       Request finished in 1.0627ms 200 text/plain; charset=utf-8
[2021-02-16T21:26:41.272Z] info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
[2021-02-16T21:26:41.272Z]       Request starting HTTP/1.1 GET http://localhost:23563/config/v1/agents?service.name=AspNetFullFramework_Tests_CentralConfigTests-CustomServiceName&service.environment=AspNetFullFramework_Tests_CentralConfigTests-CustomEnvironment  
[2021-02-16T21:26:41.272Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[3]
[2021-02-16T21:26:41.272Z]       Route matched with {action = "Get", controller = "AgentsConfig"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Get() on controller Elastic.Apm.Tests.MockApmServer.Controllers.AgentsConfigController (Elastic.Apm.Tests.MockApmServer).
[2021-02-16T21:26:41.273Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
[2021-02-16T21:26:41.273Z]       Executing action method Elastic.Apm.Tests.MockApmServer.Controllers.AgentsConfigController.Get (Elastic.Apm.Tests.MockApmServer) - Validation state: Valid
[2021-02-16T21:26:41.273Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
[2021-02-16T21:26:41.273Z]       Executed action method Elastic.Apm.Tests.MockApmServer.Controllers.AgentsConfigController.Get (Elastic.Apm.Tests.MockApmServer), returned result Microsoft.AspNetCore.Mvc.StatusCodeResult in 0.1485ms.
[2021-02-16T21:26:41.273Z] info: Microsoft.AspNetCore.Mvc.StatusCodeResult[1]
[2021-02-16T21:26:41.273Z]       Executing HttpStatusCodeResult, setting HTTP status code 304
[2021-02-16T21:26:41.273Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
[2021-02-16T21:26:41.273Z]       Executed action Elastic.Apm.Tests.MockApmServer.Controllers.AgentsConfigController.Get (Elastic.Apm.Tests.MockApmServer) in 0.3126ms
[2021-02-16T21:26:41.273Z] info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
[2021-02-16T21:26:41.273Z]       Request finished in 0.652ms 304 
[2021-02-16T21:26:41.273Z] info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
[2021-02-16T21:26:41.273Z]       Request starting HTTP/1.1 POST http://localhost:23563/intake/v2/events application/x-ndjson; charset=utf-8 2060
[2021-02-16T21:26:41.273Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[3]
[2021-02-16T21:26:41.273Z]       Route matched with {action = "Post", controller = "IntakeV2Events"}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.IActionResult] Post() on controller Elastic.Apm.Tests.MockApmServer.Controllers.IntakeV2EventsController (Elastic.Apm.Tests.MockApmServer).
[2021-02-16T21:26:41.273Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
[2021-02-16T21:26:41.273Z]       Executing action method Elastic.Apm.Tests.MockApmServer.Controllers.IntakeV2EventsController.Post (Elastic.Apm.Tests.MockApmServer) - Validation state: Valid
[2021-02-16T21:26:41.273Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
[2021-02-16T21:26:41.273Z]       Executed action method Elastic.Apm.Tests.MockApmServer.Controllers.IntakeV2EventsController.Post (Elastic.Apm.Tests.MockApmServer), returned result Microsoft.AspNetCore.Mvc.OkObjectResult in 11.4267ms.
[2021-02-16T21:26:41.273Z] info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
[2021-02-16T21:26:41.273Z]       Executing ObjectResult, writing value of type 'System.String'.
[2021-02-16T21:26:41.273Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
[2021-02-16T21:26:41.273Z]       Executed action Elastic.Apm.Tests.MockApmServer.Controllers.IntakeV2EventsController.Post (Elastic.Apm.Tests.MockApmServer) in 11.8732ms
[2021-02-16T21:26:41.273Z] info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
[2021-02-16T21:26:41.273Z]       Request finished in 12.3139ms 200 text/plain; charset=utf-8
[2021-02-16T21:26:42.214Z] info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
[2021-02-16T21:26:42.214Z]       Request starting HTTP/1.1 GET http://localhost:23563/config/v1/agents?service.name=AspNetFullFramework_Tests_CentralConfigTests-CustomServiceName&service.environment=AspNetFullFramework_Tests_CentralConfigTests-CustomEnvironment  
[2021-02-16T21:26:42.214Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[3]
[2021-02-16T21:26:42.214Z]       Route matched with {action = "Get", controller = "AgentsConfig"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Get() on controller Elastic.Apm.Tests.MockApmServer.Controllers.AgentsConfigController (Elastic.Apm.Tests.MockApmServer).
[2021-02-16T21:26:42.214Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
[2021-02-16T21:26:42.214Z]       Executing action method Elastic.Apm.Tests.MockApmServer.Controllers.AgentsConfigController.Get (Elastic.Apm.Tests.MockApmServer) - Validation state: Valid
[2021-02-16T21:26:42.214Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
[2021-02-16T21:26:42.214Z]       Executed action method Elastic.Apm.Tests.MockApmServer.Controllers.AgentsConfigController.Get (Elastic.Apm.Tests.MockApmServer), returned result Microsoft.AspNetCore.Mvc.ObjectResult in 0.16ms.
[2021-02-16T21:26:42.214Z] info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
[2021-02-16T21:26:42.214Z]       Executing ObjectResult, writing value of type 'System.String'.
[2021-02-16T21:26:42.214Z] info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
[2021-02-16T21:26:42.214Z]       Executed action Elastic.Apm.Tests.MockApmServer.Controllers.AgentsConfigController.Get (Elastic.Apm.Tests.MockApmServer) in 0.3782ms
[2021-02-16T21:26:42.214Z] info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
[2021-02-16T21:26:42.214Z]       Request finished in 0.7076ms 200 text/plain; charset=utf-8
[2021-02-16T21:26:42.788Z] Attempting to cancel the build...
[2021-02-16T21:26:42.788Z] 
[2021-02-16T21:26:42.788Z] Build FAILED.
[2021-02-16T21:26:42.788Z]     0 Warning(s)
[2021-02-16T21:26:42.788Z]     0 Error(s)
[2021-02-16T21:26:42.788Z] 
[2021-02-16T21:26:42.788Z] Time Elapsed 00:16:19.20
[2021-02-16T21:26:42.788Z] Terminate batch job (Y/N)? 
[2021-02-16T21:26:42.795Z] script returned exit code 1
[2021-02-16T21:26:44.277Z] Post stage
[2021-02-16T21:26:44.291Z] Running in C:\Users\jenkins\workspace\net_apm-agent-dotnet-mbp_PR-1135\apm-agent-dotnet
[2021-02-16T21:26:44.318Z] Archiving artifacts
[2021-02-16T21:26:45.011Z] Recording test results
[2021-02-16T21:26:46.363Z] None of the test reports contained any result
[2021-02-16T21:26:46.375Z] [Checks API] No suitable checks publisher found.
[2021-02-16T21:26:46.453Z] Post stage
[2021-02-16T21:26:46.476Z] [WS-CLEANUP] Deleting project workspace...
[2021-02-16T21:26:46.476Z] [WS-CLEANUP] Deferred wipeout is disabled by the job configuration...
[2021-02-16T21:26:52.198Z] [WS-CLEANUP] done
[2021-02-16T21:26:52.300Z] Failed in branch Windows .NET Framework
[2021-02-16T21:26:52.415Z] Stage "Release to feedz.io" skipped due to earlier failure(s)
[2021-02-16T21:26:52.463Z] Stage "Release" skipped due to earlier failure(s)
[2021-02-16T21:26:52.487Z] Stage "Release" skipped due to earlier failure(s)
[2021-02-16T21:26:52.534Z] Stage "Release" skipped due to earlier failure(s)
[2021-02-16T21:26:52.622Z] Stage "AfterRelease" skipped due to earlier failure(s)
[2021-02-16T21:26:52.645Z] Stage "AfterRelease" skipped due to earlier failure(s)
[2021-02-16T21:26:53.146Z] Running on Jenkins in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1135
[2021-02-16T21:26:53.214Z] [INFO] getVaultSecret: Getting secrets
[2021-02-16T21:26:53.452Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID
[2021-02-16T21:26:54.285Z] + chmod 755 generate-build-data.sh
[2021-02-16T21:26:54.285Z] + ./generate-build-data.sh https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1135/ https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1135/runs/28 ABORTED 3333878
[2021-02-16T21:26:54.452Z] Click here to forcibly terminate running steps
[2021-02-16T21:26:54.535Z] INFO: curl https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1135/runs/28/steps/?limit=10000 -o steps-info.json
[2021-02-16T21:26:55.446Z] INFO: curl https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1135/runs/28/tests/?status=FAILED -o tests-errors.json

@codecov-io
Copy link
Copy Markdown

codecov-io commented Jan 19, 2021

Codecov Report

Merging #1135 (7aa8069) into master (fe07407) will increase coverage by 0.19%.
The diff coverage is 90.13%.

Impacted file tree graph

@@            Coverage Diff             @@
##           master    #1135      +/-   ##
==========================================
+ Coverage   81.10%   81.30%   +0.19%     
==========================================
  Files         160      163       +3     
  Lines        6542     6681     +139     
==========================================
+ Hits         5306     5432     +126     
- Misses       1236     1249      +13     
Impacted Files Coverage Δ
src/Elastic.Apm/Agent.cs 77.50% <ø> (ø)
src/Elastic.Apm/Model/NoopSpan.cs 55.73% <0.00%> (-0.93%) ⬇️
src/Elastic.Apm/Model/NoopTransaction.cs 47.82% <0.00%> (-1.07%) ⬇️
src/Elastic.Apm/Model/ExecutionSegmentCommon.cs 91.30% <60.00%> (-3.90%) ⬇️
src/Elastic.Apm/Api/IError.cs 71.42% <71.42%> (ø)
...c/Elastic.Apm.Extensions.Logging/ApmErrorLogger.cs 85.18% <85.18%> (ø)
src/Elastic.Apm/Model/Error.cs 63.63% <92.30%> (+3.63%) ⬆️
...ic.Apm.Extensions.Hosting/HostBuilderExtensions.cs 90.27% <100.00%> (+1.21%) ⬆️
....Apm.Extensions.Logging/ApmErrorLoggingProvider.cs 100.00% <100.00%> (ø)
src/Elastic.Apm/Api/Tracer.cs 98.07% <100.00%> (+0.90%) ⬆️
... and 8 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update ba4901d...7aa8069. Read the comment docs.

Copy link
Copy Markdown
Contributor

@russcam russcam left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This looks good! I left some comments around naming

<RootNamespace>Elastic.Apm.Extensions.Logging</RootNamespace>
<AssemblyName>Elastic.Apm.Extensions.Logging</AssemblyName>
<PackageId>Elastic.Apm.Extensions.Logging</PackageId>
<Description>TODO</Description>
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Might be worth adding a description now, so it's not forgotten 😃

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Agreed :)

public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
{
if (!Agent.IsConfigured) return;
if (logLevel < LogLevel.Error) return;
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should this just use IsEnabled?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, good point. Fixed.

/// <param name="logOnError"> The logline itself </param>
/// <param name="parentId"> ParentId pointing to the parent transaction or span. </param>
/// <param name="exception"> Exception which was captured as part of the log. </param>
void CaptureLogAsError(ErrorLog logOnError, string parentId = null, Exception exception = null);
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

logOnError -> errorLog ?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍 This is a leftover from a previous renaming. Fixed.

/// <param name="logOnError"> The logline itself </param>
/// <param name="parentId"> ParentId pointing to the parent transaction or span. </param>
/// <param name="exception"> Exception which was captured as part of the log. </param>
void CaptureLogAsError(ErrorLog logOnError, string parentId = null, Exception exception = null);
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What are your thoughts here about introducing an overload to CaptureError for this? For example

void CaptureError(ErrorLog errorLog, string parentId = null, Exception exception = null);

Capturing an error log, or message and culprit (and capturing an exception too) all map to the notion of an APM error, which could be surfaced in the API with an overloaded method.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's a reasonable approach, but I don't see a huge difference.

We already have CaptureError, CaptureException, and now we'd introduce CaptureLogAsError. With this I think the method name describes better what the intention is. I don't think using overloads would be very different.


if (exception.StackTrace != null)
{
//TODO:
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

still TODO or can be removed?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah - yeah this was still ToDo - I implemented it.


public void CaptureError(string message, string culprit, StackFrame[] frames = null, string parentId = null)
{
var capturedCulprit = string.IsNullOrEmpty(culprit) ? "PublicAPI-CaptureException" : culprit;
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

should this check to see if there's a current transaction or current span here, and correlate the error with it?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch! 👍 That's also how I documented it :) Fixed now.


public void CaptureException(Exception exception, string culprit = null, bool isHandled = false, string parentId = null)
{
var capturedCulprit = string.IsNullOrEmpty(culprit) ? "PublicAPI-CaptureException" : culprit;
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same as above: should this check to see if there's a current transaction or current span here, and correlate the error with it?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍 fixed


public void CaptureLogAsError(ErrorLog errorLog, string parentId = null, Exception exception = null)
{
var error = new Error(errorLog, null, parentId, _logger) { Culprit = "Log" };
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

same as above: should this check to see if there's a current transaction or current span here, and correlate the error with it?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

👍 fixed.

Copy link
Copy Markdown
Member

@bmorelli25 bmorelli25 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Docs LG! One recommendation – take it or leave it.

==== `void CaptureError(string message, string culprit, StackFrame[] frames = null, string parentId = null);`
Use this method to capture an APM error with a message and a culprit.

NOTE: If there is an active transaction, the captured error will be correlated to it, otherwise the error will show up, but it won't be correlated to a transaction on the APM UI.
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For the three identical NOTEs on this page, how do you feel about rewording to something like this?

Captured errors are automatically correlated with the active transaction. If no transaction is active, the error will still appear in the APM app but will not be correlated with a transaction.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks, yes, sounds better. I updated to this one.

@gregkalapos gregkalapos requested a review from russcam January 28, 2021 18:14
Copy link
Copy Markdown
Contributor

@russcam russcam left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've left some comments, mainly around naming.

I think aligning method names on the concept of APM errors is useful i.e. an error in APM can be:

  1. A custom message, culprit and stack trace
  2. An exception
  3. An error level log event


[float]
[[api-start-capture-log-as-error]]
==== `void CaptureLogAsError(ErrorLog logOnError, string parentId = null, Exception exception = null);`
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
==== `void CaptureLogAsError(ErrorLog logOnError, string parentId = null, Exception exception = null);`
==== `void CaptureLogAsError(ErrorLog errorLog, string parentId = null, Exception exception = null);`


namespace Elastic.Apm.Extensions.Logging
{
internal class ElasticApmErrorLogger : ILogger
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thoughts on removing the ElasticApm prefix on the type name?

Copy link
Copy Markdown
Contributor Author

@gregkalapos gregkalapos Feb 11, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

My intention with this name was to express that this captures APM errors, which I think isn't obvious for an ILogger implementation. I added a comment and renamed to ApmErrorLogger (to include ApmError in the name).

{
if (!Agent.IsConfigured) return;
if (!IsEnabled(logLevel)) return;
if (!_agent.ConfigurationReader.Enabled || !_agent.ConfigurationReader.Recording) return;
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This feels like an important thing to point out - error logs will only be captured by the APM agent if it's enabled and recording

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I added this to the Description of the package.

if (!_agent.ConfigurationReader.Enabled || !_agent.ConfigurationReader.Recording) return;

var logLine = formatter(state, exception);
var logOnError = new ErrorLog(logLine);
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

naming nitpick :)

Suggested change
var logOnError = new ErrorLog(logLine);
var errorLog = new ErrorLog(logLine);


namespace Elastic.Apm.Extensions.Logging
{
internal class ElasticApmErrorLoggingProvider : ILoggerProvider
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thoughts on dropping the ElasticApm prefix?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same as above.

);

/// <summary>
/// Captures a log line as an APM error.
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should we adopt log event to describe a log?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes. Seems MS docs also use log event. Changed it.

HttpVersion = "2.0",
Socket = new Socket { Encrypted = true, RemoteAddress = "127.0.0.1" },
Body = "123"
HttpVersion = "2.0", Socket = new Socket { Encrypted = true, RemoteAddress = "127.0.0.1" }, Body = "123"
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

formatting?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, this was Rider, no real change here - I don't have an opinion on formatting - my only opinion is that it should be standardized and never be an issue :) I wonder why this happened on my machine and how we could standardize this. Maybe I'll check if .editorconfig could help here.

I changed this back to the original.

@russcam russcam added enhancement New feature or request v1.8.0 labels Feb 11, 2021

[float]
[[api-start-capture-error-log]]
==== `void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null);`
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
==== `void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null);`
==== `void CaptureErrorLog(ErrorLog errorLog, string parentId = null, Exception exception = null);`

[[api-start-capture-error-log]]
==== `void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null);`

Use this method to capture a log line as an APM error.
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
Use this method to capture a log line as an APM error.
Use this method to capture a log event as an APM error.


[float]
[[api-transaction-capture-error-log]]
==== `void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null);`
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
==== `void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null);`
==== `void CaptureErrorLog(ErrorLog errorLog, string parentId = null, Exception exception = null);`

/// <param name="parentId"> ParentId pointing to the parent transaction or span. </param>
/// <param name="exception"> Exception which was captured as part of the log. </param>
/// <param name="labels">Labels that will be added to the captured error</param>
void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null);
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null);
void CaptureErrorLog(ErrorLog errorLog, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null);

/// <param name="serverInfo"></param>
/// <param name="exception"></param>
/// <param name="labels"></param>
internal static void CaptureLogAsError(ErrorLog logOnError, IPayloadSender payloadSender, IApmLogger logger,
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
internal static void CaptureLogAsError(ErrorLog logOnError, IPayloadSender payloadSender, IApmLogger logger,
internal static void CaptureLogAsError(ErrorLog errorLog, IPayloadSender payloadSender, IApmLogger logger,

Dictionary<string, Label> labels = null
) { }

public void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
public void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null
public void CaptureErrorLog(ErrorLog errorLog, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null

return false;
}

public void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
public void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null
public void CaptureErrorLog(ErrorLog errorLog, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null

public void SetLabel(string key, decimal value)
=> Context.InternalLabels.Value.InnerDictionary[key] = value;

public void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null)
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
public void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null)
public void CaptureErrorLog(ErrorLog errorLog, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null)

return name;
}

public void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null)
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
public void CaptureErrorLog(ErrorLog logOnError, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null)
public void CaptureErrorLog(ErrorLog errorLog, string parentId = null, Exception exception = null, Dictionary<string, Label> labels = null)

Comment on lines +23 to +24
public IDisposable BeginScope<TState>(TState state) =>
null;
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Even though this logger may not support scopes, should this return an instance of an IDisposable, so that usage via ILogger still works e.g.

private class NullScope: IDisposable
{
    public NullScope() {}
    public Dispose() {}
}

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Changed it.

}

/// <summary>
/// Represents a log line which is captured as part of an APM error.
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
/// Represents a log line which is captured as part of an APM error.
/// Represents a log event which is captured as part of an APM error.

public string Message { get; set; }

/// <summary>
/// A parametrized message. E.g. 'Could not connect to %s'. The property message is still required, and should be equal
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
/// A parametrized message. E.g. 'Could not connect to %s'. The property message is still required, and should be equal
/// A parameterized message. E.g. 'Could not connect to %s'. The property message is still required, and should be equal

/// A parametrized message. E.g. 'Could not connect to %s'. The property message is still required, and should be equal
/// to the param_message, but with placeholders replaced. In some situations the param_message is used to group errors
/// together.
/// The string is not interpreted, so feel free to use whichever placeholders makes sense in the client languange."
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
/// The string is not interpreted, so feel free to use whichever placeholders makes sense in the client languange."
/// The string is not interpreted, so feel free to use whichever placeholders makes sense in the client language."

/// <summary>
/// Captures a log event as an APM error.
/// </summary>
/// <param name="errorLog"> The log line itself </param>
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
/// <param name="errorLog"> The log line itself </param>
/// <param name="errorLog"> The log event </param>

}

[Fact]
public void CaptureLogAsErrorOnSpan()
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
public void CaptureLogAsErrorOnSpan()
public void CaptureErrorLogOnSpan()

}

[Fact]
public void CaptureLogAsErrorOnTracer()
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
public void CaptureLogAsErrorOnTracer()
public void CaptureErrorLogOnTracer()

}

[Fact]
public void CaptureLogOnTracerWithActiveSpan()
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
public void CaptureLogOnTracerWithActiveSpan()
public void CaptureErrorLogOnTracerWithActiveSpan()

}

[Fact]
public void CaptureLogOnTracerWithActiveTransaction()
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
public void CaptureLogOnTracerWithActiveTransaction()
public void CaptureErrorLogOnTracerWithActiveTransaction()

}

[Fact]
public void CaptureLogAsErrorOnTransaction()
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
public void CaptureLogAsErrorOnTransaction()
public void CaptureErrorLogOnTransaction()

Copy link
Copy Markdown
Contributor

@russcam russcam left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM 👍

@gregkalapos
Copy link
Copy Markdown
Contributor Author

I was watching CI for this to be green - next time please ping.

@gregkalapos
Copy link
Copy Markdown
Contributor Author

gregkalapos commented Feb 16, 2021

It's late here, the last CI run almost finished, but due to the push it got cancelled. The 1 failing test seems to be unrelated. I'm hitting merge.

Please next time ask before you push on other's branch.

@gregkalapos gregkalapos merged commit 5addb61 into elastic:master Feb 16, 2021
@gregkalapos gregkalapos deleted the ErrorLogsAsApmErrors branch February 16, 2021 21:30
@ghost
Copy link
Copy Markdown

ghost commented Feb 16, 2021

💚 Build Succeeded

the below badges are clickable and redirect to their specific view in the CI or DOCS
Pipeline View Test View Changes Artifacts preview

Expand to view the summary

Build stats

  • Build Cause: Pull request #1135 updated

  • Start Time: 2021-02-16T21:24:10.553+0000

  • Duration: 56 min 6 sec

  • Commit: 026d1d0

Test stats 🧪

Test Results
Failed 0
Passed 18240
Skipped 76
Total 18316

Trends 🧪

Image of Build Times

Image of Tests

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

APM ILoggerProvider Implementation

4 participants