Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix nullref in Elastic.Apm.Extensions.Logging #1311

Merged
merged 2 commits into from
May 27, 2021
Merged

Fix nullref in Elastic.Apm.Extensions.Logging #1311

merged 2 commits into from
May 27, 2021

Conversation

gregkalapos
Copy link
Contributor

@gregkalapos gregkalapos commented May 26, 2021

Fixes #1309

Also extended the test to cover the case where the nullref happened.

@@ -42,7 +42,7 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except

if (_agent is ApmAgent apmAgent && exception != null)
{
errorLog.StackTrace = StacktraceHelper.GenerateApmStackTrace(exception, null, "CaptureErrorLogsAsApmError",
Copy link
Contributor Author

Choose a reason for hiding this comment

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

This was the problem 🤦

@apmmachine
Copy link
Contributor

apmmachine commented May 26, 2021

💔 Tests Failed

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 #1311 updated

  • Start Time: 2021-05-27T15:22:19.011+0000

  • Duration: 44 min 7 sec

  • Commit: 9b2d1c1

Test stats 🧪

Test Results
Failed 7
Passed 17614
Skipped 77
Total 17698

Trends 🧪

Image of Build Times

Image of Tests

Test errors 7

Expand to view the tests failures

Initializing / Parallel / Linux / Test / BasicDockerTests.Elastic.Apm.Docker.Tests.BasicDockerTests.ContainerIdExistsTest – Elastic.Apm.Docker.Tests.BasicDockerTests
    Expand to view the error details

     Expected payloadSender?.System.Container.Id not to be <null>. 
    

    Expand to view the stacktrace

     Expected payloadSender?.System.Container.Id not to be <null>.
    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.ReferenceTypeAssertions`2.NotBeNull(String because, Object[] becauseArgs) in C:\projects\fluentassertions-vf06b\Src\FluentAssertions\Primitives\ReferenceTypeAssertions.cs:line 62
       at Elastic.Apm.Docker.Tests.BasicDockerTests.ContainerIdExistsTest() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1311/apm-agent-dotnet/test/Elastic.Apm.Docker.Tests/BasicDockerTests.cs:line 25 
    

Initializing / Parallel / Linux / Test / BasicDockerTests.Elastic.Apm.Docker.Tests.BasicDockerTests.ContainerIdExistsTest – Elastic.Apm.Docker.Tests.BasicDockerTests
    Expand to view the error details

     Expected payloadSender?.System.Container.Id not to be <null>. 
    

    Expand to view the stacktrace

     Expected payloadSender?.System.Container.Id not to be <null>.
    Stack Trace:
       at FluentAssertions.Execution.XUnit2TestFramework.Throw(String message)
       at FluentAssertions.Execution.TestFrameworkProvider.Throw(String message)
       at FluentAssertions.Execution.DefaultAssertionStrategy.HandleFailure(String message)
       at FluentAssertions.Execution.AssertionScope.FailWith(Func`1 failReasonFunc)
       at FluentAssertions.Execution.AssertionScope.FailWith(String message, Object[] args)
       at FluentAssertions.Primitives.ReferenceTypeAssertions`2.NotBeNull(String because, Object[] becauseArgs)
       at Elastic.Apm.Docker.Tests.BasicDockerTests.ContainerIdExistsTest() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1311/apm-agent-dotnet/test/Elastic.Apm.Docker.Tests/BasicDockerTests.cs:line 25 
    

Initializing / Parallel / Linux / Test / BasicDockerTests.Elastic.Apm.Docker.Tests.BasicDockerTests.ContainerIdExistsTest – Elastic.Apm.Docker.Tests.BasicDockerTests
    Expand to view the error details

     Expected payloadSender?.System.Container.Id not to be <null>. 
    

    Expand to view the stacktrace

     Expected payloadSender?.System.Container.Id not to be <null>.
    Stack Trace:
       at FluentAssertions.Execution.XUnit2TestFramework.Throw(String message)
       at FluentAssertions.Execution.TestFrameworkProvider.Throw(String message)
       at FluentAssertions.Execution.DefaultAssertionStrategy.HandleFailure(String message)
       at FluentAssertions.Execution.AssertionScope.FailWith(Func`1 failReasonFunc)
       at FluentAssertions.Execution.AssertionScope.FailWith(String message, Object[] args)
       at FluentAssertions.Primitives.ReferenceTypeAssertions`2.NotBeNull(String because, Object[] becauseArgs)
       at Elastic.Apm.Docker.Tests.BasicDockerTests.ContainerIdExistsTest() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1311/apm-agent-dotnet/test/Elastic.Apm.Docker.Tests/BasicDockerTests.cs:line 25 
    

Initializing / Parallel / Linux / Test / HttpDiagnosticListenerTests.Elastic.Apm.Tests.HttpDiagnosticListenerTests.NoWarningWithNoTransaction – Elastic.Apm.Tests.HttpDiagnosticListenerTests
    Expand to view the error details

     Expected collection {"[2021-05-27 15:38:10.273 +00:00][Trace] - {PlatformDetection} Version based on RuntimeInformation.FrameworkDescription (`.NET Core 4.6.27414.06') is `4.6.27414.06'", "[2021-05-27 15:38:10.276 +00:00][Debug] - {Service} Environment.Version (`4.0.30319.42000') and version (`4.6.27414.06') from RuntimeInformation.FrameworkDescription (`.NET Core 4.6.27414.06') don't refer to the same version", "[2021-05-27 15:38:10.276 +00:00][Debug] - {Service} Falling back on using System assembly file location (`/var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1311/apm-agent-dotnet/.dotnet/shared/Microsoft.NETCore.App/2.1.9/System.Private.CoreLib.dll') - returning (`2.1.9')", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 12:memory:/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 10:cpu,cpuacct:/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 6:blkio:/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 5:pids:/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 3:devices:/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 1:name=systemd:/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 0::/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id", "[2021-05-27 15:38:10.276 +00:00][Debug] - {HttpDiagnosticListener} Current runtime is not detected as Full Framework - returning implementation for Core. RuntimeInformation.FrameworkDescription: .NET Core 4.6.27414.06", "[2021-05-27 15:38:10.276 +00:00][Trace] - {DiagnosticInitializer} There are no listeners in the current batch (Elastic.Apm.DiagnosticListeners.HttpDiagnosticListenerCoreImpl) that would like to subscribe to `Microsoft.AspNetCore' events source", "[2021-05-27 15:38:10.276 +00:00][Trace] - {DiagnosticInitializer} There are no listeners in the current batch (Elastic.Apm.DiagnosticListeners.HttpDiagnosticListenerCoreImpl) that would like to subscribe to `Microsoft.AspNetCore' events source", "[2021-05-27 15:38:10.277 +00:00][Debug] - {DiagnosticInitializer} Subscribed Elastic.Apm.DiagnosticListeners.HttpDiagnosticListenerCoreImpl to `HttpHandlerDiagnosticListener' events source", "[2021-05-27 15:38:10.277 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Start'", "[2021-05-27 15:38:10.277 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing start event... Request URL: https://elastic.co/", "[2021-05-27 15:38:10.277 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} No current transaction, skip creating span for outgoing HTTP request", "[2021-05-27 15:38:10.277 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Request'", "[2021-05-27 15:38:10.277 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Unrecognized key `System.Net.Http.Request'", "[2021-05-27 15:38:10.457 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Stop'", "[2021-05-27 15:38:10.457 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing stop event... Request URL: https://www.elastic.co/", "[2021-05-27 15:38:10.457 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} ProcessStopEvent called with no active current transaction, url: https://www.elastic.co/ - skipping event", "[2021-05-27 15:38:10.457 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Response'", "[2021-05-27 15:38:10.457 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Event's Request property is null - exiting"} to not have any items matching line.ToLower().Contains("warn"), but found {"[2021-05-27 15:38:10.276 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id"}. 
    

    Expand to view the stacktrace

     Expected collection {"[2021-05-27 15:38:10.273 +00:00][Trace] - {PlatformDetection} Version based on RuntimeInformation.FrameworkDescription (`.NET Core 4.6.27414.06') is `4.6.27414.06'", "[2021-05-27 15:38:10.276 +00:00][Debug] - {Service} Environment.Version (`4.0.30319.42000') and version (`4.6.27414.06') from RuntimeInformation.FrameworkDescription (`.NET Core 4.6.27414.06') don't refer to the same version", "[2021-05-27 15:38:10.276 +00:00][Debug] - {Service} Falling back on using System assembly file location (`/var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1311/apm-agent-dotnet/.dotnet/shared/Microsoft.NETCore.App/2.1.9/System.Private.CoreLib.dll') - returning (`2.1.9')", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 12:memory:/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 10:cpu,cpuacct:/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 6:blkio:/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 5:pids:/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 3:devices:/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 1:name=systemd:/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 0::/system.slice/runsvdir.service", "[2021-05-27 15:38:10.276 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id", "[2021-05-27 15:38:10.276 +00:00][Debug] - {HttpDiagnosticListener} Current runtime is not detected as Full Framework - returning implementation for Core. RuntimeInformation.FrameworkDescription: .NET Core 4.6.27414.06", "[2021-05-27 15:38:10.276 +00:00][Trace] - {DiagnosticInitializer} There are no listeners in the current batch (Elastic.Apm.DiagnosticListeners.HttpDiagnosticListenerCoreImpl) that would like to subscribe to `Microsoft.AspNetCore' events source", "[2021-05-27 15:38:10.276 +00:00][Trace] - {DiagnosticInitializer} There are no listeners in the current batch (Elastic.Apm.DiagnosticListeners.HttpDiagnosticListenerCoreImpl) that would like to subscribe to `Microsoft.AspNetCore' events source", "[2021-05-27 15:38:10.277 +00:00][Debug] - {DiagnosticInitializer} Subscribed Elastic.Apm.DiagnosticListeners.HttpDiagnosticListenerCoreImpl to `HttpHandlerDiagnosticListener' events source", "[2021-05-27 15:38:10.277 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Start'", "[2021-05-27 15:38:10.277 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing start event... Request URL: https://elastic.co/", "[2021-05-27 15:38:10.277 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} No current transaction, skip creating span for outgoing HTTP request", "[2021-05-27 15:38:10.277 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Request'", "[2021-05-27 15:38:10.277 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Unrecognized key `System.Net.Http.Request'", "[2021-05-27 15:38:10.457 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Stop'", "[2021-05-27 15:38:10.457 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing stop event... Request URL: https://www.elastic.co/", "[2021-05-27 15:38:10.457 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} ProcessStopEvent called with no active current transaction, url: https://www.elastic.co/ - skipping event", "[2021-05-27 15:38:10.457 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Response'", "[2021-05-27 15:38:10.457 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Event's Request property is null - exiting"} to not have any items matching line.ToLower().Contains("warn"), but found {"[2021-05-27 15:38:10.276 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id"}.
    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.Collections.SelfReferencingCollectionAssertions`2.NotContain(Expression`1 predicate, String because, Object[] becauseArgs) in C:\projects\fluentassertions-vf06b\Src\FluentAssertions\Collections\SelfReferencingCollectionAssertions.cs:line 589
       at Elastic.Apm.Tests.HttpDiagnosticListenerTests.NoWarningWithNoTransaction()
    --- End of stack trace from previous location where exception was thrown --- 
    

Initializing / Parallel / Linux / Test / HttpDiagnosticListenerTests.Elastic.Apm.Tests.HttpDiagnosticListenerTests.NoWarningWithNoTransaction – Elastic.Apm.Tests.HttpDiagnosticListenerTests
    Expand to view the error details

     Expected logger.Lines {"[2021-05-27 15:40:27.514 +00:00][Trace] - {PlatformDetection} Version based on RuntimeInformation.FrameworkDescription (`.NET Core 3.0.3') is `3.0.3'", "[2021-05-27 15:40:27.520 +00:00][Debug] - {Service} Environment.Version (`3.0.3') and RuntimeInformation.FrameworkDescription (`.NET Core 3.0.3') refer to the same version (`3.0.3') - returning it", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 12:memory:/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 10:cpu,cpuacct:/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 6:blkio:/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 5:pids:/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 3:devices:/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 1:name=systemd:/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 0::/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id", "[2021-05-27 15:40:27.521 +00:00][Debug] - {HttpDiagnosticListener} Current runtime is not detected as Full Framework - returning implementation for Core. RuntimeInformation.FrameworkDescription: .NET Core 3.0.3", "[2021-05-27 15:40:27.521 +00:00][Debug] - {DiagnosticInitializer} Subscribed Elastic.Apm.DiagnosticListeners.HttpDiagnosticListenerCoreImpl to `HttpHandlerDiagnosticListener' events source", "[2021-05-27 15:40:27.521 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Start'", "[2021-05-27 15:40:27.521 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing start event... Request URL: https://elastic.co/", "[2021-05-27 15:40:27.521 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} No current transaction, skip creating span for outgoing HTTP request", "[2021-05-27 15:40:27.521 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Request'", "[2021-05-27 15:40:27.521 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Unrecognized key `System.Net.Http.Request'", "[2021-05-27 15:40:27.630 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Stop'", "[2021-05-27 15:40:27.630 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing stop event... Request URL: https://www.elastic.co/", "[2021-05-27 15:40:27.630 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} ProcessStopEvent called with no active current transaction, url: https://www.elastic.co/ - skipping event", "[2021-05-27 15:40:27.630 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Response'", "[2021-05-27 15:40:27.630 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Event's Request property is null - exiting"} to not have any items matching line.ToLower().Contains("warn"), but found {"[2021-05-27 15:40:27.521 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id"}. 
    

    Expand to view the stacktrace

     Expected logger.Lines {"[2021-05-27 15:40:27.514 +00:00][Trace] - {PlatformDetection} Version based on RuntimeInformation.FrameworkDescription (`.NET Core 3.0.3') is `3.0.3'", "[2021-05-27 15:40:27.520 +00:00][Debug] - {Service} Environment.Version (`3.0.3') and RuntimeInformation.FrameworkDescription (`.NET Core 3.0.3') refer to the same version (`3.0.3') - returning it", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 12:memory:/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 10:cpu,cpuacct:/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 6:blkio:/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 5:pids:/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 3:devices:/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 1:name=systemd:/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 0::/system.slice/runsvdir.service", "[2021-05-27 15:40:27.521 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id", "[2021-05-27 15:40:27.521 +00:00][Debug] - {HttpDiagnosticListener} Current runtime is not detected as Full Framework - returning implementation for Core. RuntimeInformation.FrameworkDescription: .NET Core 3.0.3", "[2021-05-27 15:40:27.521 +00:00][Debug] - {DiagnosticInitializer} Subscribed Elastic.Apm.DiagnosticListeners.HttpDiagnosticListenerCoreImpl to `HttpHandlerDiagnosticListener' events source", "[2021-05-27 15:40:27.521 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Start'", "[2021-05-27 15:40:27.521 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing start event... Request URL: https://elastic.co/", "[2021-05-27 15:40:27.521 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} No current transaction, skip creating span for outgoing HTTP request", "[2021-05-27 15:40:27.521 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Request'", "[2021-05-27 15:40:27.521 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Unrecognized key `System.Net.Http.Request'", "[2021-05-27 15:40:27.630 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Stop'", "[2021-05-27 15:40:27.630 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing stop event... Request URL: https://www.elastic.co/", "[2021-05-27 15:40:27.630 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} ProcessStopEvent called with no active current transaction, url: https://www.elastic.co/ - skipping event", "[2021-05-27 15:40:27.630 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Response'", "[2021-05-27 15:40:27.630 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Event's Request property is null - exiting"} to not have any items matching line.ToLower().Contains("warn"), but found {"[2021-05-27 15:40:27.521 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id"}.
    Stack Trace:
       at FluentAssertions.Execution.XUnit2TestFramework.Throw(String message)
       at FluentAssertions.Execution.TestFrameworkProvider.Throw(String message)
       at FluentAssertions.Execution.DefaultAssertionStrategy.HandleFailure(String message)
       at FluentAssertions.Execution.AssertionScope.FailWith(Func`1 failReasonFunc)
       at FluentAssertions.Collections.SelfReferencingCollectionAssertions`2.NotContain(Expression`1 predicate, String because, Object[] becauseArgs)
       at Elastic.Apm.Tests.HttpDiagnosticListenerTests.NoWarningWithNoTransaction() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1311/apm-agent-dotnet/test/Elastic.Apm.Tests/HttpDiagnosticListenerTests.cs:line 781
    --- End of stack trace from previous location where exception was thrown --- 
    

Initializing / Parallel / Linux / Test / HttpDiagnosticListenerTests.Elastic.Apm.Tests.HttpDiagnosticListenerTests.NoWarningWithNoTransaction – Elastic.Apm.Tests.HttpDiagnosticListenerTests
    Expand to view the error details

     Expected logger.Lines {"[2021-05-27 15:42:04.403 +00:00][Trace] - {PlatformDetection} Version based on RuntimeInformation.FrameworkDescription (`.NET Core 3.1.0') is `3.1.0'", "[2021-05-27 15:42:04.403 +00:00][Debug] - {Service} Environment.Version (`3.1.0') and RuntimeInformation.FrameworkDescription (`.NET Core 3.1.0') refer to the same version (`3.1.0') - returning it", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 12:memory:/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 10:cpu,cpuacct:/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 6:blkio:/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 5:pids:/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 3:devices:/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 1:name=systemd:/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 0::/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id", "[2021-05-27 15:42:04.404 +00:00][Debug] - {HttpDiagnosticListener} Current runtime is not detected as Full Framework - returning implementation for Core. RuntimeInformation.FrameworkDescription: .NET Core 3.1.0", "[2021-05-27 15:42:04.404 +00:00][Debug] - {DiagnosticInitializer} Subscribed Elastic.Apm.DiagnosticListeners.HttpDiagnosticListenerCoreImpl to `HttpHandlerDiagnosticListener' events source", "[2021-05-27 15:42:04.404 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Start'", "[2021-05-27 15:42:04.404 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing start event... Request URL: https://elastic.co/", "[2021-05-27 15:42:04.404 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} No current transaction, skip creating span for outgoing HTTP request", "[2021-05-27 15:42:04.404 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Request'", "[2021-05-27 15:42:04.404 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Unrecognized key `System.Net.Http.Request'", "[2021-05-27 15:42:04.539 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Stop'", "[2021-05-27 15:42:04.539 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing stop event... Request URL: https://www.elastic.co/", "[2021-05-27 15:42:04.539 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} ProcessStopEvent called with no active current transaction, url: https://www.elastic.co/ - skipping event", "[2021-05-27 15:42:04.539 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Response'", "[2021-05-27 15:42:04.539 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Event's Request property is null - exiting"} to not have any items matching line.ToLower().Contains("warn"), but found {"[2021-05-27 15:42:04.404 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id"}. 
    

    Expand to view the stacktrace

     Expected logger.Lines {"[2021-05-27 15:42:04.403 +00:00][Trace] - {PlatformDetection} Version based on RuntimeInformation.FrameworkDescription (`.NET Core 3.1.0') is `3.1.0'", "[2021-05-27 15:42:04.403 +00:00][Debug] - {Service} Environment.Version (`3.1.0') and RuntimeInformation.FrameworkDescription (`.NET Core 3.1.0') refer to the same version (`3.1.0') - returning it", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 12:memory:/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 10:cpu,cpuacct:/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 6:blkio:/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 5:pids:/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 3:devices:/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 1:name=systemd:/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 0::/system.slice/runsvdir.service", "[2021-05-27 15:42:04.404 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id", "[2021-05-27 15:42:04.404 +00:00][Debug] - {HttpDiagnosticListener} Current runtime is not detected as Full Framework - returning implementation for Core. RuntimeInformation.FrameworkDescription: .NET Core 3.1.0", "[2021-05-27 15:42:04.404 +00:00][Debug] - {DiagnosticInitializer} Subscribed Elastic.Apm.DiagnosticListeners.HttpDiagnosticListenerCoreImpl to `HttpHandlerDiagnosticListener' events source", "[2021-05-27 15:42:04.404 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Start'", "[2021-05-27 15:42:04.404 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing start event... Request URL: https://elastic.co/", "[2021-05-27 15:42:04.404 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} No current transaction, skip creating span for outgoing HTTP request", "[2021-05-27 15:42:04.404 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Request'", "[2021-05-27 15:42:04.404 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Unrecognized key `System.Net.Http.Request'", "[2021-05-27 15:42:04.539 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Stop'", "[2021-05-27 15:42:04.539 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing stop event... Request URL: https://www.elastic.co/", "[2021-05-27 15:42:04.539 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} ProcessStopEvent called with no active current transaction, url: https://www.elastic.co/ - skipping event", "[2021-05-27 15:42:04.539 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Response'", "[2021-05-27 15:42:04.539 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Event's Request property is null - exiting"} to not have any items matching line.ToLower().Contains("warn"), but found {"[2021-05-27 15:42:04.404 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id"}.
    Stack Trace:
       at FluentAssertions.Execution.XUnit2TestFramework.Throw(String message)
       at FluentAssertions.Execution.TestFrameworkProvider.Throw(String message)
       at FluentAssertions.Execution.DefaultAssertionStrategy.HandleFailure(String message)
       at FluentAssertions.Execution.AssertionScope.FailWith(Func`1 failReasonFunc)
       at FluentAssertions.Collections.SelfReferencingCollectionAssertions`2.NotContain(Expression`1 predicate, String because, Object[] becauseArgs)
       at Elastic.Apm.Tests.HttpDiagnosticListenerTests.NoWarningWithNoTransaction() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1311/apm-agent-dotnet/test/Elastic.Apm.Tests/HttpDiagnosticListenerTests.cs:line 781
    --- End of stack trace from previous location where exception was thrown --- 
    

Initializing / Parallel / Linux / Test / HttpDiagnosticListenerTests.Elastic.Apm.Tests.HttpDiagnosticListenerTests.NoWarningWithNoTransaction – Elastic.Apm.Tests.HttpDiagnosticListenerTests
    Expand to view the error details

     Expected logger.Lines {"[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 12:memory:/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 10:cpu,cpuacct:/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 6:blkio:/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 5:pids:/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 3:devices:/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 1:name=systemd:/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 0::/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id", "[2021-05-27 15:46:19.214 +00:00][Debug] - {HttpDiagnosticListener} Current runtime is not detected as Full Framework - returning implementation for Core. RuntimeInformation.FrameworkDescription: .NET 5.0.6", "[2021-05-27 15:46:19.214 +00:00][Debug] - {DiagnosticInitializer} Subscribed Elastic.Apm.DiagnosticListeners.HttpDiagnosticListenerCoreImpl to `HttpHandlerDiagnosticListener' events source", "[2021-05-27 15:46:19.214 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Start'", "[2021-05-27 15:46:19.214 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing start event... Request URL: https://elastic.co/", "[2021-05-27 15:46:19.215 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} No current transaction, skip creating span for outgoing HTTP request", "[2021-05-27 15:46:19.215 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Request'", "[2021-05-27 15:46:19.215 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Unrecognized key `System.Net.Http.Request'", "[2021-05-27 15:46:19.332 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Stop'", "[2021-05-27 15:46:19.333 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing stop event... Request URL: https://www.elastic.co/", "[2021-05-27 15:46:19.333 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} ProcessStopEvent called with no active current transaction, url: https://www.elastic.co/ - skipping event", "[2021-05-27 15:46:19.333 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Response'", "[2021-05-27 15:46:19.333 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Event's Request property is null - exiting"} to not have any items matching line.ToLower().Contains("warn"), but found {"[2021-05-27 15:46:19.214 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id"}. 
    

    Expand to view the stacktrace

     Expected logger.Lines {"[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 12:memory:/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 10:cpu,cpuacct:/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 6:blkio:/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 5:pids:/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 3:devices:/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 1:name=systemd:/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Debug] - {SystemInfoHelper} Could not parse container ID from '/proc/self/cgroup' line: 0::/system.slice/runsvdir.service", "[2021-05-27 15:46:19.214 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id", "[2021-05-27 15:46:19.214 +00:00][Debug] - {HttpDiagnosticListener} Current runtime is not detected as Full Framework - returning implementation for Core. RuntimeInformation.FrameworkDescription: .NET 5.0.6", "[2021-05-27 15:46:19.214 +00:00][Debug] - {DiagnosticInitializer} Subscribed Elastic.Apm.DiagnosticListeners.HttpDiagnosticListenerCoreImpl to `HttpHandlerDiagnosticListener' events source", "[2021-05-27 15:46:19.214 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Start'", "[2021-05-27 15:46:19.214 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing start event... Request URL: https://elastic.co/", "[2021-05-27 15:46:19.215 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} No current transaction, skip creating span for outgoing HTTP request", "[2021-05-27 15:46:19.215 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Request'", "[2021-05-27 15:46:19.215 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Unrecognized key `System.Net.Http.Request'", "[2021-05-27 15:46:19.332 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.HttpRequestOut.Stop'", "[2021-05-27 15:46:19.333 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Processing stop event... Request URL: https://www.elastic.co/", "[2021-05-27 15:46:19.333 +00:00][Debug] - {HttpDiagnosticListenerCoreImpl} ProcessStopEvent called with no active current transaction, url: https://www.elastic.co/ - skipping event", "[2021-05-27 15:46:19.333 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Called with key: `System.Net.Http.Response'", "[2021-05-27 15:46:19.333 +00:00][Trace] - {HttpDiagnosticListenerCoreImpl} Event's Request property is null - exiting"} to not have any items matching line.ToLower().Contains("warn"), but found {"[2021-05-27 15:46:19.214 +00:00][Warning] - {SystemInfoHelper} Failed parsing container id - the agent will not report container id"}.
    Stack Trace:
       at FluentAssertions.Execution.XUnit2TestFramework.Throw(String message)
       at FluentAssertions.Execution.TestFrameworkProvider.Throw(String message)
       at FluentAssertions.Execution.DefaultAssertionStrategy.HandleFailure(String message)
       at FluentAssertions.Execution.AssertionScope.FailWith(Func`1 failReasonFunc)
       at FluentAssertions.Collections.SelfReferencingCollectionAssertions`2.NotContain(Expression`1 predicate, String because, Object[] becauseArgs)
       at Elastic.Apm.Tests.HttpDiagnosticListenerTests.NoWarningWithNoTransaction() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1311/apm-agent-dotnet/test/Elastic.Apm.Tests/HttpDiagnosticListenerTests.cs:line 781
    --- End of stack trace from previous location --- 
    

Steps errors 2

Expand to view the steps failures

Windows Batch Script
  • Took 0 min 5 sec . View more details on here
  • Description: .ci/windows/msbuild.bat
Archive the artifacts
  • Took 0 min 1 sec . View more details on here
  • Description: [2021-05-27T15:38:41.148Z] Archiving artifacts script returned exit code 1

Log output

Expand to view the last 100 lines of log output

[2021-05-27T16:05:33.634Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Schema/ValidationEventArgs.cs. 
[2021-05-27T16:05:33.634Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Converters/StringEnumConverter.cs. 
[2021-05-27T16:05:33.732Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Converters/StringEnumConverter.cs. 
[2021-05-27T16:05:33.732Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Utilities/DynamicProxyMetaObject.cs. 
[2021-05-27T16:05:33.814Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Utilities/DynamicProxyMetaObject.cs. 
[2021-05-27T16:05:33.814Z] Starting copy source file Libraries/Newtonsoft.Json/Converters/StringEnumConverter.cs. 
[2021-05-27T16:05:33.897Z] Copied Libraries/Newtonsoft.Json/Converters/StringEnumConverter.cs. 
[2021-05-27T16:05:33.897Z] Starting copy source file Libraries/Newtonsoft.Json/Serialization/JsonPrimitiveContract.cs. 
[2021-05-27T16:05:33.970Z] Copied Libraries/Newtonsoft.Json/Serialization/JsonPrimitiveContract.cs. 
[2021-05-27T16:05:33.970Z] Starting copy source file Elastic.Apm/Config/AbstractConfigurationReader.cs. 
[2021-05-27T16:05:34.065Z] Copied Elastic.Apm/Config/AbstractConfigurationReader.cs. 
[2021-05-27T16:05:34.065Z] Starting copy source file Elastic.Apm/Filters/SpanStackTraceCapturingFilter.cs. 
[2021-05-27T16:05:34.142Z] Copied Elastic.Apm/Filters/SpanStackTraceCapturingFilter.cs. 
[2021-05-27T16:05:34.142Z] Starting copy source file Elastic.Apm/Helpers/ContractExtensions.cs. 
[2021-05-27T16:05:34.223Z] Copied Elastic.Apm/Helpers/ContractExtensions.cs. 
[2021-05-27T16:05:34.223Z] Starting copy source file Libraries/Newtonsoft.Json/Schema/JsonSchemaBuilder.cs. 
[2021-05-27T16:05:34.305Z] Copied Libraries/Newtonsoft.Json/Schema/JsonSchemaBuilder.cs. 
[2021-05-27T16:05:34.305Z] Starting copy source file Report/Serialization/MetricSetConverter.cs. 
[2021-05-27T16:05:34.383Z] Copied Report/Serialization/MetricSetConverter.cs. 
[2021-05-27T16:05:34.384Z] Starting copy source file Libraries/Newtonsoft.Json/Utilities/DynamicProxy.cs. 
[2021-05-27T16:05:34.462Z] Copied Libraries/Newtonsoft.Json/Utilities/DynamicProxy.cs. 
[2021-05-27T16:05:34.462Z] Starting copy source file Cloud/AzureCloudMetadataProvider.cs. 
[2021-05-27T16:05:34.539Z] Copied Cloud/AzureCloudMetadataProvider.cs. 
[2021-05-27T16:05:34.539Z] Starting copy source file Api/Context.cs. 
[2021-05-27T16:05:34.615Z] Copied Api/Context.cs. 
[2021-05-27T16:05:34.615Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Serialization/DefaultContractResolver.cs. 
[2021-05-27T16:05:34.726Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Serialization/DefaultContractResolver.cs. 
[2021-05-27T16:05:34.726Z] Starting copy source file Elastic.Apm/Logging/LogValuesFormatter.cs. 
[2021-05-27T16:05:34.814Z] Copied Elastic.Apm/Logging/LogValuesFormatter.cs. 
[2021-05-27T16:05:34.814Z] Starting copy source file Config/AbstractConfigurationReader.cs. 
[2021-05-27T16:05:34.913Z] Copied Config/AbstractConfigurationReader.cs. 
[2021-05-27T16:06:22.396Z] [Checks API] No suitable checks publisher found.
[2021-05-27T16:06:22.539Z] [INFO] getVaultSecret: Getting secrets
[2021-05-27T16:06:22.593Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID
[2021-05-27T16:06:23.179Z] Running in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1311/apm-agent-dotnet
[2021-05-27T16:06:23.203Z] [INFO] Codecov: Getting branch ref...
[2021-05-27T16:06:23.313Z] Masking supported pattern matches of $GITHUB_TOKEN
[2021-05-27T16:06:23.848Z] [INFO] Codecov: Sending data...
[2021-05-27T16:06:24.533Z] + echo curl -sSLo codecov.sh https://codecov.io/bash
[2021-05-27T16:06:24.533Z] curl -sSLo codecov.sh https://codecov.io/bash
[2021-05-27T16:06:24.864Z] + echo bash codecov.sh
[2021-05-27T16:06:24.864Z] bash codecov.sh
[2021-05-27T16:06:24.985Z] Archiving artifacts
[2021-05-27T16:06:25.050Z] java.lang.InterruptedException: no matches found within 10000
[2021-05-27T16:06:25.051Z] 	at hudson.FilePath$ValidateAntFileMask.hasMatch(FilePath.java:3069)
[2021-05-27T16:06:25.051Z] 	at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2978)
[2021-05-27T16:06:25.051Z] 	at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2929)
[2021-05-27T16:06:25.051Z] 	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3317)
[2021-05-27T16:06:25.051Z] Also:   hudson.remoting.Channel$CallSiteStackTrace: Remote call to apm-ci-immutable-ubuntu-1804-1622128953647027614
[2021-05-27T16:06:25.051Z] 		at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1800)
[2021-05-27T16:06:25.051Z] 		at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:356)
[2021-05-27T16:06:25.051Z] 		at hudson.remoting.Channel.call(Channel.java:1001)
[2021-05-27T16:06:25.051Z] 		at hudson.FilePath.act(FilePath.java:1159)
[2021-05-27T16:06:25.051Z] 		at hudson.FilePath.act(FilePath.java:1148)
[2021-05-27T16:06:25.051Z] 		at hudson.FilePath.validateAntFileMask(FilePath.java:2927)
[2021-05-27T16:06:25.051Z] 		at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:270)
[2021-05-27T16:06:25.051Z] 		at org.jenkinsci.plugins.workflow.steps.CoreStep$Execution.run(CoreStep.java:99)
[2021-05-27T16:06:25.051Z] 		at org.jenkinsci.plugins.workflow.steps.CoreStep$Execution.run(CoreStep.java:69)
[2021-05-27T16:06:25.051Z] 		at org.jenkinsci.plugins.workflow.steps.SynchronousNonBlockingStepExecution.lambda$start$0(SynchronousNonBlockingStepExecution.java:47)
[2021-05-27T16:06:25.051Z] 		at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[2021-05-27T16:06:25.051Z] 		at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[2021-05-27T16:06:25.051Z] 		at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[2021-05-27T16:06:25.051Z] 		at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[2021-05-27T16:06:25.051Z] Caused: hudson.FilePath$TunneledInterruptedException
[2021-05-27T16:06:25.051Z] 	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3319)
[2021-05-27T16:06:25.051Z] 	at hudson.remoting.UserRequest.perform(UserRequest.java:211)
[2021-05-27T16:06:25.051Z] 	at hudson.remoting.UserRequest.perform(UserRequest.java:54)
[2021-05-27T16:06:25.051Z] 	at hudson.remoting.Request$2.run(Request.java:375)
[2021-05-27T16:06:25.051Z] 	at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:73)
[2021-05-27T16:06:25.051Z] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[2021-05-27T16:06:25.051Z] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[2021-05-27T16:06:25.051Z] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[2021-05-27T16:06:25.051Z] 	at hudson.remoting.Engine$1.lambda$newThread$0(Engine.java:118)
[2021-05-27T16:06:25.051Z] Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
[2021-05-27T16:06:25.051Z] 	at hudson.FilePath.act(FilePath.java:1161)
[2021-05-27T16:06:25.051Z] 	at hudson.FilePath.act(FilePath.java:1148)
[2021-05-27T16:06:25.051Z] 	at hudson.FilePath.validateAntFileMask(FilePath.java:2927)
[2021-05-27T16:06:25.051Z] 	at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:270)
[2021-05-27T16:06:25.051Z] 	at org.jenkinsci.plugins.workflow.steps.CoreStep$Execution.run(CoreStep.java:99)
[2021-05-27T16:06:25.051Z] 	at org.jenkinsci.plugins.workflow.steps.CoreStep$Execution.run(CoreStep.java:69)
[2021-05-27T16:06:25.051Z] 	at org.jenkinsci.plugins.workflow.steps.SynchronousNonBlockingStepExecution.lambda$start$0(SynchronousNonBlockingStepExecution.java:47)
[2021-05-27T16:06:25.051Z] 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[2021-05-27T16:06:25.051Z] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[2021-05-27T16:06:25.051Z] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[2021-05-27T16:06:25.051Z] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[2021-05-27T16:06:25.051Z] 	at java.lang.Thread.run(Thread.java:748)
[2021-05-27T16:06:25.051Z] No artifacts found that match the file pattern "/var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1311/**/MSBuild_*.failure.txt". Configuration error?
[2021-05-27T16:06:25.254Z] Stage "Release to feedz.io" skipped due to earlier failure(s)
[2021-05-27T16:06:25.296Z] Stage "Release" skipped due to earlier failure(s)
[2021-05-27T16:06:25.316Z] Stage "Release" skipped due to earlier failure(s)
[2021-05-27T16:06:25.362Z] Stage "Release" skipped due to earlier failure(s)
[2021-05-27T16:06:25.442Z] Stage "AfterRelease" skipped due to earlier failure(s)
[2021-05-27T16:06:25.466Z] Stage "AfterRelease" skipped due to earlier failure(s)
[2021-05-27T16:06:25.765Z] Running on Jenkins in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1311
[2021-05-27T16:06:25.819Z] [INFO] getVaultSecret: Getting secrets
[2021-05-27T16:06:25.877Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID
[2021-05-27T16:06:26.620Z] + chmod 755 generate-build-data.sh
[2021-05-27T16:06:26.620Z] + ./generate-build-data.sh https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1311/ https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1311/runs/3 FAILURE 2647345
[2021-05-27T16:06:26.620Z] INFO: curl https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1311/runs/3/steps/?limit=10000 -o steps-info.json
[2021-05-27T16:06:27.276Z] INFO: curl https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1311/runs/3/tests/?status=FAILED -o tests-errors.json

Copy link
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.

The null conditional operator on logger inside GenerateApmStackTrace look unnecessary. Removing them would avoid performing a null check on each logger invocation.

@@ -48,7 +48,7 @@ internal static class StacktraceHelper
var len = stackTraceLimit == -1 ? frames.Length : Math.Min(frames.Length, stackTraceLimit);
var retVal = new List<CapturedStackFrame>(len);

logger.Trace()?.Log("transform stack frames");
logger?.Trace()?.Log("transform stack frames");
Copy link
Contributor

Choose a reason for hiding this comment

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

The null conditional operator on logger looks unneccessary. StacktraceHelper is internal and GenerateApmStackTrace is called only by agent code where the logger should never be null (if it is null, it's a bug).

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Ok, there were some calls on logger with .? and some without it - I removed it from all of them.

@@ -64,7 +64,7 @@ internal static class StacktraceHelper

var fileName = frame?.GetFileName();

logger.Trace()?.Log("{MethodName}, {lineNo}", functionName, frame?.GetFileLineNumber());
logger?.Trace()?.Log("{MethodName}, {lineNo}", functionName, frame?.GetFileLineNumber());
Copy link
Contributor

Choose a reason for hiding this comment

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

The null conditional operator on logger looks unneccessary. StacktraceHelper is internal and GenerateApmStackTrace is called only by agent code where the logger should never be null (if it is null, it's a bug).

@@ -42,7 +42,7 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except

if (_agent is ApmAgent apmAgent && exception != null)
{
errorLog.StackTrace = StacktraceHelper.GenerateApmStackTrace(exception, null, "CaptureErrorLogsAsApmError",
errorLog.StackTrace = StacktraceHelper.GenerateApmStackTrace(exception, _agent.Logger, "CaptureErrorLogsAsApmError",
Copy link
Contributor

Choose a reason for hiding this comment

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

minor nitpick:

Suggested change
errorLog.StackTrace = StacktraceHelper.GenerateApmStackTrace(exception, _agent.Logger, "CaptureErrorLogsAsApmError",
errorLog.StackTrace = StacktraceHelper.GenerateApmStackTrace(exception, apmAgent.Logger, "CaptureErrorLogsAsApmError",

It makes no difference either way, but reads more intuitively to me, since the other passed values come from apmAgent

@gregkalapos gregkalapos merged commit e0452d6 into elastic:master May 27, 2021
@gregkalapos gregkalapos deleted the NullRefFixInExtensionsLogging branch May 27, 2021 16:25
v1v added a commit to v1v/apm-agent-dotnet that referenced this pull request Jun 8, 2021
…u-20

* upstream/master: (21 commits)
  Prefer W3C traceparent over elastic-apm-traceparent (elastic#1302)
  fix spacing and cross references in docs (elastic#1328)
  Update README (elastic#1325)
  Mark MicrosoftAzureBlobStorageTracer internal (elastic#1326)
  Update docs (elastic#1327)
  Update context.destination.address (elastic#1324)
  synchronize json schema specs (elastic#1320)
  Don't package Elastic.Apm.Specification (elastic#1316)
  Update setup.asciidoc (elastic#1318)
  Prepare release v.1.10.0 (elastic#1314)
  Fix nullref in Elastic.Apm.Extensions.Logging (elastic#1311)
  Capture errors with startup hook auto instrumentation (elastic#1298)
  Use Logger to log exception in AgentComponents initialization (elastic#1305)
  fix: use .NET native SDK for build and test (elastic#1301)
  Skip running Elasticsearch docker test when docker not available (elastic#1312)
  Use TraceLogger as default logger in ASP.NET Full Framework (elastic#1288)
  Create receive messaging span when inside transaction (elastic#1308)
  Fix SanitizeFieldNamesTests (elastic#1299)
  Do not capture HTTP child spans for Elasticsearch (elastic#1306)
  Use storage account in destination.service.resource (elastic#1284)
  ...
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

NullReferenceException ApmErrorLogger/GenerateApmStackTrace
3 participants