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

Use TraceLogger as default logger in ASP.NET Full Framework #1288

Merged
merged 2 commits into from
May 27, 2021

Conversation

russcam
Copy link
Contributor

@russcam russcam commented May 4, 2021

This commit adds a logger implementation, TraceLogger, that
writes agent logs to a TraceSource with name "Elastic.Apm".
This logger is configured as the default logger for
ASP.NET Full Framework applications, which can use configuration
to write log messages to file, debug window, Windows event log, etc.

Add a section to docs with an example of how to configure
the logger in web.config.

Move the default log level from ConsoleLogger into DefaultValues.

Closes #1263

This commit adds a logger implementation, TraceLogger, that
writes agent logs to a TraceSource with name "Elastic.Apm".
This logger is configured as the default logger for
ASP.NET Full Framework applications, which can use configuration
to write log messages to file, debug window, Windows event log, etc.

Add a section to docs with an example of how to configure
the logger in web.config.

Move the default log level from ConsoleLogger into DefaultValues.

Closes elastic#1263
@russcam russcam added enhancement New feature or request v1.10.0 labels May 4, 2021
@apmmachine
Copy link
Contributor

apmmachine commented May 4, 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: Branch indexing

  • Start Time: 2021-05-26T02:20:46.933+0000

  • Duration: 124 min 45 sec

  • Commit: ea47331

Test stats 🧪

Test Results
Failed 312
Passed 16621
Skipped 74
Total 17007

Trends 🧪

Image of Build Times

Image of Tests

Test errors 312

Expand to view the tests failures

> Show only the first 10 test failures

Initializing / Parallel / Linux / Test / ElasticsearchTests.Elastic.Apm.Elasticsearch.Tests.ElasticsearchTests.Elasticsearch_Span_Does_Not_Have_Http_Child_Span – Elastic.Apm.Elasticsearch.Tests.ElasticsearchTests
    Expand to view the error details

     Expected searchResponse.Success to be true, but found False. 
    

    Expand to view the stacktrace

     Expected searchResponse.Success to be true, but found False.
    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.BooleanAssertions.BeTrue(String because, Object[] becauseArgs) in C:\projects\fluentassertions-vf06b\Src\FluentAssertions\Primitives\BooleanAssertions.cs:line 59
       at Elastic.Apm.Elasticsearch.Tests.ElasticsearchTests.Elasticsearch_Span_Does_Not_Have_Http_Child_Span() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/test/Elastic.Apm.Elasticsearch.Tests/ElasticsearchTests.cs:line 39
    --- End of stack trace from previous location where exception was thrown --- 
    

Initializing / Parallel / Windows .NET Core / Test / ElasticsearchTests.Elastic.Apm.Elasticsearch.Tests.ElasticsearchTests.Elasticsearch_Span_Does_Not_Have_Http_Child_Span – Elastic.Apm.Elasticsearch.Tests.ElasticsearchTests
    Expand to view the error details

     System.TypeInitializationException : The type initializer for 'DotNet.Testcontainers.Client.DockerApiClient' threw an exception.
    ---- System.TimeoutException : The operation has timed out. 
    

    Expand to view the stacktrace

     System.TypeInitializationException : The type initializer for 'DotNet.Testcontainers.Client.DockerApiClient' threw an exception.
    ---- System.TimeoutException : The operation has timed out.
    Stack Trace:
       at DotNet.Testcontainers.Client.DockerApiClientImage.ByPropertyAsync(String property, String value)
       at DotNet.Testcontainers.Client.DockerApiClientImage.ByNameAsync(String name)
       at DotNet.Testcontainers.Client.AbstractContainerImageClient`1.ExistsWithNameAsync(String name)
       at DotNet.Testcontainers.Client.TestcontainersClient.RunAsync(TestcontainersConfiguration config, CancellationToken ct)
       at DotNet.Testcontainers.Containers.Modules.TestcontainersContainer.Create()
       at DotNet.Testcontainers.Containers.Modules.TestcontainersContainer.StartAsync()
       at Elastic.Apm.Elasticsearch.Tests.ElasticsearchFixture.InitializeAsync() in C:\Users\jenkins\workspace\net_apm-agent-dotnet-mbp_PR-1288\apm-agent-dotnet\test\Elastic.Apm.Elasticsearch.Tests\ElasticsearchFixture.cs:line 30
    ----- Inner Stack Trace -----
       at System.IO.Pipes.NamedPipeClientStream.ConnectInternal(Int32 timeout, CancellationToken cancellationToken, Int32 startTime)
       at System.IO.Pipes.NamedPipeClientStream.<>c__DisplayClass20_0.<ConnectAsync>b__0()
       at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
    --- End of stack trace from previous location where exception was thrown ---
       at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot)
    --- End of stack trace from previous location where exception was thrown ---
       at Docker.DotNet.DockerClient.<>c__DisplayClass6_0.<<-ctor>b__0>d.MoveNext()
    --- End of stack trace from previous location where exception was thrown ---
       at Microsoft.Net.Http.Client.ManagedHandler.ProcessRequestAsync(HttpRequestMessage request, CancellationToken cancellationToken)
       at Microsoft.Net.Http.Client.ManagedHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
       at System.Net.Http.HttpClient.FinishSendAsyncBuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
       at Docker.DotNet.DockerClient.PrivateMakeRequestAsync(TimeSpan timeout, HttpCompletionOption completionOption, HttpMethod method, String path, IQueryString queryString, IDictionary`2 headers, IRequestContent data, CancellationToken cancellationToken)
       at Docker.DotNet.DockerClient.PrivateMakeRequestAsync(TimeSpan timeout, HttpCompletionOption completionOption, HttpMethod method, String path, IQueryString queryString, IDictionary`2 headers, IRequestContent data, CancellationToken cancellationToken)
       at Docker.DotNet.DockerClient.MakeRequestAsync(IEnumerable`1 errorHandlers, HttpMethod method, String path, IQueryString queryString, IRequestContent body, IDictionary`2 headers, TimeSpan timeout, CancellationToken token)
       at Docker.DotNet.SystemOperations.GetSystemInfoAsync(CancellationToken cancellationToken)
       at DotNet.Testcontainers.Client.DockerApiClient..cctor() 
    

Initializing / Parallel / Linux / Test / SanitizeFieldNamesTests.Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(headerName: "secret", useOnlyDiagnosticSource: True) – Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests
    Expand to view the error details

     Expected _capturedPayload.Transactions to contain a single item, but the collection is empty. 
    

    Expand to view the stacktrace

     Expected _capturedPayload.Transactions to contain a single item, but the collection is empty.
    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.ContainSingle(String because, Object[] becauseArgs) in C:\projects\fluentassertions-vf06b\Src\FluentAssertions\Collections\SelfReferencingCollectionAssertions.cs:line 611
       at Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(String headerName, Boolean useOnlyDiagnosticSource) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/test/Elastic.Apm.AspNetCore.Tests/SanitizeFieldNamesTests.cs:line 295
    --- End of stack trace from previous location where exception was thrown --- 
    

Initializing / Parallel / Linux / Test / SanitizeFieldNamesTests.Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(headerName: "usersessionid", useOnlyDiagnosticSource: True) – Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests
    Expand to view the error details

     Expected _capturedPayload.Transactions to contain a single item, but the collection is empty. 
    

    Expand to view the stacktrace

     Expected _capturedPayload.Transactions to contain a single item, but the collection is empty.
    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.ContainSingle(String because, Object[] becauseArgs) in C:\projects\fluentassertions-vf06b\Src\FluentAssertions\Collections\SelfReferencingCollectionAssertions.cs:line 611
       at Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(String headerName, Boolean useOnlyDiagnosticSource) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/test/Elastic.Apm.AspNetCore.Tests/SanitizeFieldNamesTests.cs:line 295
    --- End of stack trace from previous location where exception was thrown --- 
    

Initializing / Parallel / Linux / Test / SanitizeFieldNamesTests.Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(headerName: "secret", useOnlyDiagnosticSource: False) – Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests
    Expand to view the error details

     System.Net.Http.HttpRequestException : Error while copying content to a stream.
    ---- System.IO.IOException : 
    -------- System.InvalidOperationException : Collection was modified; enumeration operation may not execute. 
    

    Expand to view the stacktrace

     System.Net.Http.HttpRequestException : Error while copying content to a stream.
    ---- System.IO.IOException : 
    -------- System.InvalidOperationException : Collection was modified; enumeration operation may not execute.
    Stack Trace:
       at System.Net.Http.HttpContent.LoadIntoBufferAsyncCore(Task serializeToStreamTask, MemoryStream tempBuffer)
       at System.Net.Http.HttpClient.FinishSendAsyncBuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
       at Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(String headerName, Boolean useOnlyDiagnosticSource) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/test/Elastic.Apm.AspNetCore.Tests/SanitizeFieldNamesTests.cs:line 292
    --- End of stack trace from previous location where exception was thrown ---
    ----- Inner Stack Trace -----
       at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
       at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
       at System.IO.Pipelines.Pipe.GetReadAsyncResult()
       at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
       at Microsoft.AspNetCore.TestHost.ResponseStream.ReadAsync(Byte[] buffer, Int32 offset, Int32 count, CancellationToken cancellationToken)
       at System.IO.Stream.CopyToAsyncInternal(Stream destination, Int32 bufferSize, CancellationToken cancellationToken)
       at System.Net.Http.StreamToStreamCopy.<>c.<DisposeSourceWhenCompleteAsync>b__1_0(Task completed, Object innerSource)
       at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
    --- End of stack trace from previous location where exception was thrown ---
       at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot)
    --- End of stack trace from previous location where exception was thrown ---
       at System.Net.Http.HttpContent.LoadIntoBufferAsyncCore(Task serializeToStreamTask, MemoryStream tempBuffer)
    ----- Inner Stack Trace -----
       at System.Collections.Generic.Dictionary`2.KeyCollection.Enumerator.MoveNext()
       at Elastic.Apm.Filters.HeaderDictionarySanitizerFilter.Filter(ITransaction transaction) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/src/Elastic.Apm/Filters/HeaderDictionarySanitizerFilter.cs:line 25
       at System.Linq.Enumerable.Aggregate[TSource,TAccumulate](IEnumerable`1 source, TAccumulate seed, Func`3 func)
       at Elastic.Apm.Tests.Utilities.MockPayloadSender.QueueTransaction(ITransaction transaction) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/test/Elastic.Apm.Tests.Utilities/MockPayloadSender.cs:line 185
       at Elastic.Apm.Model.Transaction.End() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/src/Elastic.Apm/Model/Transaction.cs:line 480
       at Elastic.Apm.AspNetCore.WebRequestTransactionCreator.StopTransaction(Transaction transaction, HttpContext context, IApmLogger logger)
       at Elastic.Apm.AspNetCore.ApmMiddleware.InvokeAsync(HttpContext context) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/src/Elastic.Apm.AspNetCore/ApmMiddleware.cs:line 58
       at Microsoft.AspNetCore.TestHost.HttpContextBuilder.<>c__DisplayClass10_0.<<SendAsync>b__0>d.MoveNext() 
    

Initializing / Parallel / Linux / Test / SanitizeFieldNamesTests.Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(headerName: "password", useOnlyDiagnosticSource: True) – Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests
    Expand to view the error details

     Expected _capturedPayload.Transactions to contain a single item, but the collection is empty. 
    

    Expand to view the stacktrace

     Expected _capturedPayload.Transactions to contain a single item, but the collection is empty.
    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.ContainSingle(String because, Object[] becauseArgs) in C:\projects\fluentassertions-vf06b\Src\FluentAssertions\Collections\SelfReferencingCollectionAssertions.cs:line 611
       at Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(String headerName, Boolean useOnlyDiagnosticSource) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/test/Elastic.Apm.AspNetCore.Tests/SanitizeFieldNamesTests.cs:line 295
    --- End of stack trace from previous location where exception was thrown --- 
    

Initializing / Parallel / Linux / Test / SanitizeFieldNamesTests.Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(headerName: "pwd", useOnlyDiagnosticSource: False) – Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests
    Expand to view the error details

     System.Net.Http.HttpRequestException : Error while copying content to a stream.
    ---- System.IO.IOException : 
    -------- System.InvalidOperationException : Collection was modified; enumeration operation may not execute. 
    

    Expand to view the stacktrace

     System.Net.Http.HttpRequestException : Error while copying content to a stream.
    ---- System.IO.IOException : 
    -------- System.InvalidOperationException : Collection was modified; enumeration operation may not execute.
    Stack Trace:
       at System.Net.Http.HttpContent.LoadIntoBufferAsyncCore(Task serializeToStreamTask, MemoryStream tempBuffer)
       at System.Net.Http.HttpClient.FinishSendAsyncBuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
       at Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(String headerName, Boolean useOnlyDiagnosticSource) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/test/Elastic.Apm.AspNetCore.Tests/SanitizeFieldNamesTests.cs:line 292
    --- End of stack trace from previous location where exception was thrown ---
    ----- Inner Stack Trace -----
       at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
       at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
       at System.IO.Pipelines.Pipe.GetReadAsyncResult()
       at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
       at Microsoft.AspNetCore.TestHost.ResponseStream.ReadAsync(Byte[] buffer, Int32 offset, Int32 count, CancellationToken cancellationToken)
       at System.IO.Stream.CopyToAsyncInternal(Stream destination, Int32 bufferSize, CancellationToken cancellationToken)
       at System.Net.Http.StreamToStreamCopy.<>c.<DisposeSourceWhenCompleteAsync>b__1_0(Task completed, Object innerSource)
       at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
    --- End of stack trace from previous location where exception was thrown ---
       at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot)
    --- End of stack trace from previous location where exception was thrown ---
       at System.Net.Http.HttpContent.LoadIntoBufferAsyncCore(Task serializeToStreamTask, MemoryStream tempBuffer)
    ----- Inner Stack Trace -----
       at System.Collections.Generic.Dictionary`2.KeyCollection.Enumerator.MoveNext()
       at Elastic.Apm.Filters.HeaderDictionarySanitizerFilter.Filter(ITransaction transaction) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/src/Elastic.Apm/Filters/HeaderDictionarySanitizerFilter.cs:line 25
       at System.Linq.Enumerable.Aggregate[TSource,TAccumulate](IEnumerable`1 source, TAccumulate seed, Func`3 func)
       at Elastic.Apm.Tests.Utilities.MockPayloadSender.QueueTransaction(ITransaction transaction) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/test/Elastic.Apm.Tests.Utilities/MockPayloadSender.cs:line 185
       at Elastic.Apm.Model.Transaction.End() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/src/Elastic.Apm/Model/Transaction.cs:line 480
       at Elastic.Apm.AspNetCore.WebRequestTransactionCreator.StopTransaction(Transaction transaction, HttpContext context, IApmLogger logger)
       at Elastic.Apm.AspNetCore.ApmMiddleware.InvokeAsync(HttpContext context) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/src/Elastic.Apm.AspNetCore/ApmMiddleware.cs:line 58
       at Microsoft.AspNetCore.TestHost.HttpContextBuilder.<>c__DisplayClass10_0.<<SendAsync>b__0>d.MoveNext() 
    

Initializing / Parallel / Linux / Test / SanitizeFieldNamesTests.Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(headerName: "usertokensecret", useOnlyDiagnosticSource: True) – Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests
    Expand to view the error details

     Expected _capturedPayload.Transactions to contain a single item, but the collection is empty. 
    

    Expand to view the stacktrace

     Expected _capturedPayload.Transactions to contain a single item, but the collection is empty.
    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.ContainSingle(String because, Object[] becauseArgs) in C:\projects\fluentassertions-vf06b\Src\FluentAssertions\Collections\SelfReferencingCollectionAssertions.cs:line 611
       at Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(String headerName, Boolean useOnlyDiagnosticSource) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/test/Elastic.Apm.AspNetCore.Tests/SanitizeFieldNamesTests.cs:line 295
    --- End of stack trace from previous location where exception was thrown --- 
    

Initializing / Parallel / Linux / Test / SanitizeFieldNamesTests.Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(headerName: "usertokensecret", useOnlyDiagnosticSource: False) – Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests
    Expand to view the error details

     System.Net.Http.HttpRequestException : Error while copying content to a stream.
    ---- System.IO.IOException : 
    -------- System.InvalidOperationException : Collection was modified; enumeration operation may not execute. 
    

    Expand to view the stacktrace

     System.Net.Http.HttpRequestException : Error while copying content to a stream.
    ---- System.IO.IOException : 
    -------- System.InvalidOperationException : Collection was modified; enumeration operation may not execute.
    Stack Trace:
       at System.Net.Http.HttpContent.LoadIntoBufferAsyncCore(Task serializeToStreamTask, MemoryStream tempBuffer)
       at System.Net.Http.HttpClient.FinishSendAsyncBuffered(Task`1 sendTask, HttpRequestMessage request, CancellationTokenSource cts, Boolean disposeCts)
       at Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(String headerName, Boolean useOnlyDiagnosticSource) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/test/Elastic.Apm.AspNetCore.Tests/SanitizeFieldNamesTests.cs:line 292
    --- End of stack trace from previous location where exception was thrown ---
    ----- Inner Stack Trace -----
       at System.IO.Pipelines.PipeCompletion.ThrowLatchedException()
       at System.IO.Pipelines.Pipe.GetReadResult(ReadResult& result)
       at System.IO.Pipelines.Pipe.GetReadAsyncResult()
       at System.IO.Pipelines.Pipe.DefaultPipeReader.GetResult(Int16 token)
       at Microsoft.AspNetCore.TestHost.ResponseStream.ReadAsync(Byte[] buffer, Int32 offset, Int32 count, CancellationToken cancellationToken)
       at System.IO.Stream.CopyToAsyncInternal(Stream destination, Int32 bufferSize, CancellationToken cancellationToken)
       at System.Net.Http.StreamToStreamCopy.<>c.<DisposeSourceWhenCompleteAsync>b__1_0(Task completed, Object innerSource)
       at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
    --- End of stack trace from previous location where exception was thrown ---
       at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot)
    --- End of stack trace from previous location where exception was thrown ---
       at System.Net.Http.HttpContent.LoadIntoBufferAsyncCore(Task serializeToStreamTask, MemoryStream tempBuffer)
    ----- Inner Stack Trace -----
       at System.Collections.Generic.Dictionary`2.KeyCollection.Enumerator.MoveNext()
       at Elastic.Apm.Filters.HeaderDictionarySanitizerFilter.Filter(ITransaction transaction) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/src/Elastic.Apm/Filters/HeaderDictionarySanitizerFilter.cs:line 25
       at System.Linq.Enumerable.Aggregate[TSource,TAccumulate](IEnumerable`1 source, TAccumulate seed, Func`3 func)
       at Elastic.Apm.Tests.Utilities.MockPayloadSender.QueueTransaction(ITransaction transaction) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/test/Elastic.Apm.Tests.Utilities/MockPayloadSender.cs:line 185
       at Elastic.Apm.Model.Transaction.End() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/src/Elastic.Apm/Model/Transaction.cs:line 480
       at Elastic.Apm.AspNetCore.WebRequestTransactionCreator.StopTransaction(Transaction transaction, HttpContext context, IApmLogger logger)
       at Elastic.Apm.AspNetCore.ApmMiddleware.InvokeAsync(HttpContext context) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/src/Elastic.Apm.AspNetCore/ApmMiddleware.cs:line 58
       at Microsoft.AspNetCore.TestHost.HttpContextBuilder.<>c__DisplayClass10_0.<<SendAsync>b__0>d.MoveNext() 
    

Initializing / Parallel / Linux / Test / SanitizeFieldNamesTests.Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(headerName: "secretcreditcard", useOnlyDiagnosticSource: True) – Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests
    Expand to view the error details

     Expected _capturedPayload.Transactions to contain a single item, but the collection is empty. 
    

    Expand to view the stacktrace

     Expected _capturedPayload.Transactions to contain a single item, but the collection is empty.
    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.ContainSingle(String because, Object[] becauseArgs) in C:\projects\fluentassertions-vf06b\Src\FluentAssertions\Collections\SelfReferencingCollectionAssertions.cs:line 611
       at Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.DefaultsWithHeaders(String headerName, Boolean useOnlyDiagnosticSource) in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/test/Elastic.Apm.AspNetCore.Tests/SanitizeFieldNamesTests.cs:line 295
    --- End of stack trace from previous location where exception was thrown --- 
    

Steps errors 6

Expand to view the steps failures

Archive the artifacts
  • Took 0 min 0 sec . View more details on here
  • Description: [2021-05-26T04:24:30.152Z] Archiving artifacts withAzureCredentials: error org.jenkinsci.plugins.wo
Windows Batch Script
  • Took 0 min 4 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-26T02:36:20.337Z] Archiving artifacts script returned exit code 1
Build
  • Took 1 min 1 sec . View more details on here
  • Description: .ci/windows/dotnet.bat
Archive the artifacts
  • Took 0 min 0 sec . View more details on here
  • Description: [2021-05-26T04:23:48.763Z] Archiving artifacts withAzureCredentials: error org.jenkinsci.plugins.wo
Error signal
  • Took 0 min 0 sec . View more details on here
  • Description: withAzureCredentials: error org.jenkinsci.plugins.workflow.steps.FlowInterruptedException

Log output

Expand to view the last 100 lines of log output

[2021-05-26T04:23:30.786Z] info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
[2021-05-26T04:23:30.787Z]       Request finished in 7.4728ms 200 text/plain; charset=utf-8
[2021-05-26T04:23:31.047Z]   Passed Elastic.Apm.AspNetCore.Tests.SanitizeFieldNamesTests.CustomWithRequestBodyNoError(sanitizeFieldNames: "(?-i)mysecurityheader", formName: "mySECURITYHeader", shouldBeSanitized: False, useOnlyDiagnosticSource: False) [1 s]
[2021-05-26T04:23:31.390Z] Attempting to cancel the build...
[2021-05-26T04:23:31.390Z] Attempting to cancel the build...
[2021-05-26T04:23:31.390Z] Attempting to cancel the build...
[2021-05-26T04:23:31.390Z] Attempting to cancel the build...
[2021-05-26T04:23:31.390Z]          Build continuing because "ContinueOnError" on the task "MSBuild" is set to "ErrorAndContinue".
[2021-05-26T04:23:31.390Z]      8>Done Building Project "C:\Users\jenkins\workspace\net_apm-agent-dotnet-mbp_PR-1288\apm-agent-dotnet\test\Elastic.Apm.AspNetCore.Tests\Elastic.Apm.AspNetCore.Tests.csproj" (VSTest target(s)) -- FAILED.
[2021-05-26T04:23:31.390Z]      1>Done Building Project "C:\Users\jenkins\workspace\net_apm-agent-dotnet-mbp_PR-1288\apm-agent-dotnet\ElasticApmAgent.sln" (VSTest target(s)) -- FAILED.
[2021-05-26T04:23:31.390Z] 
[2021-05-26T04:23:31.390Z] Build FAILED.
[2021-05-26T04:23:31.390Z]     0 Warning(s)
[2021-05-26T04:23:31.390Z]     0 Error(s)
[2021-05-26T04:23:31.390Z] 
[2021-05-26T04:23:31.390Z] Time Elapsed 01:43:09.19
[2021-05-26T04:23:31.390Z] Application is shutting down...
[2021-05-26T04:23:31.390Z] Terminate batch job (Y/N)? 
[2021-05-26T04:23:31.397Z] script returned exit code 1
[2021-05-26T04:23:31.705Z] Sending interrupt signal to process
[2021-05-26T04:23:32.238Z] Running in C:\Users\jenkins\workspace\net_apm-agent-dotnet-mbp_PR-1288
[2021-05-26T04:23:32.520Z] info: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[0]
[2021-05-26T04:23:32.521Z]       User profile is available. Using '/var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet/.aspnet/DataProtection-Keys' as key repository; keys will not be encrypted at rest.
[2021-05-26T04:23:32.521Z] info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
[2021-05-26T04:23:32.521Z]       Request starting HTTP/1.1 POST http://localhost/api/Home/Post application/x-www-form-urlencoded 
[2021-05-26T04:23:32.521Z] warn: Microsoft.AspNetCore.HttpsPolicy.HttpsRedirectionMiddleware[3]
[2021-05-26T04:23:32.521Z]       Failed to determine the https port for redirect.
[2021-05-26T04:23:32.521Z] info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
[2021-05-26T04:23:32.521Z]       Executing endpoint 'SampleAspNetCoreApp.Controllers.HomeController.Post (SampleAspNetCoreApp)'
[2021-05-26T04:23:32.522Z] info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
[2021-05-26T04:23:32.522Z]       Route matched with {action = "Post", controller = "Home", area = "", page = ""}. Executing controller action with signature Microsoft.AspNetCore.Mvc.ActionResult`1[System.String] Post() on controller SampleAspNetCoreApp.Controllers.HomeController (SampleAspNetCoreApp).
[2021-05-26T04:23:32.522Z] info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[1]
[2021-05-26T04:23:32.522Z]       Executing action method SampleAspNetCoreApp.Controllers.HomeController.Post (SampleAspNetCoreApp) - Validation state: Valid
[2021-05-26T04:23:32.522Z] info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
[2021-05-26T04:23:32.522Z]       Executed action method SampleAspNetCoreApp.Controllers.HomeController.Post (SampleAspNetCoreApp), returned result Microsoft.AspNetCore.Mvc.ObjectResult in 0.0039ms.
[2021-05-26T04:23:32.522Z] info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
[2021-05-26T04:23:32.523Z]       Executing ObjectResult, writing value of type 'System.String'.
[2021-05-26T04:23:32.523Z] info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
[2021-05-26T04:23:32.523Z]       Executed action SampleAspNetCoreApp.Controllers.HomeController.Post (SampleAspNetCoreApp) in 1.1077ms
[2021-05-26T04:23:32.523Z] info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
[2021-05-26T04:23:32.523Z]       Executed endpoint 'SampleAspNetCoreApp.Controllers.HomeController.Post (SampleAspNetCoreApp)'
[2021-05-26T04:23:32.523Z] info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
[2021-05-26T04:23:32.524Z]       Request finished in 11.5978ms 200 text/plain; charset=utf-8
[2021-05-26T04:23:32.524Z] Terminated
[2021-05-26T04:23:32.619Z] script returned exit code 143
[2021-05-26T04:23:32.665Z] 
[2021-05-26T04:23:32.665Z] C:\Users\jenkins\workspace\net_apm-agent-dotnet-mbp_PR-1288>del .credentials.json 
[2021-05-26T04:23:32.666Z] Running in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet
[2021-05-26T04:23:33.174Z] + rm .credentials.json
[2021-05-26T04:23:33.269Z] $ docker stop --time=1 23f37124bb950fa75548bd27b79059e63f5a7f4b451a1fec3b41e9fb837f78b3
[2021-05-26T04:23:34.613Z] $ docker rm -f 23f37124bb950fa75548bd27b79059e63f5a7f4b451a1fec3b41e9fb837f78b3
[2021-05-26T04:23:34.955Z] Post stage
[2021-05-26T04:23:35.036Z] Running in C:\Users\jenkins\workspace\net_apm-agent-dotnet-mbp_PR-1288\apm-agent-dotnet
[2021-05-26T04:23:35.064Z] Archiving artifacts
[2021-05-26T04:23:35.939Z] Post stage
[2021-05-26T04:23:35.972Z] Running in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288/apm-agent-dotnet
[2021-05-26T04:23:36.014Z] Archiving artifacts
[2021-05-26T04:23:41.740Z] Recording test results
[2021-05-26T04:23:42.729Z] Recording test results
[2021-05-26T04:23:47.522Z] [Checks API] No suitable checks publisher found.
[2021-05-26T04:23:48.507Z] [Checks API] No suitable checks publisher found.
[2021-05-26T04:23:48.699Z] Publishing Coverage report....
[2021-05-26T04:23:48.763Z] Archiving artifacts
[2021-05-26T04:23:48.842Z] Stage "Startup Hook Tests" skipped due to earlier failure(s)
[2021-05-26T04:23:48.869Z] Post stage
[2021-05-26T04:23:48.895Z] [WS-CLEANUP] Deleting project workspace...
[2021-05-26T04:23:48.895Z] [WS-CLEANUP] Deferred wipeout is disabled by the job configuration...
[2021-05-26T04:23:54.888Z] [WS-CLEANUP] done
[2021-05-26T04:23:55.025Z] Failed in branch Windows .NET Core
[2021-05-26T04:24:30.058Z] Body did not finish within grace period; terminating with extreme prejudice
[2021-05-26T04:24:30.072Z] Error when executing always post condition:
[2021-05-26T04:24:30.073Z] org.jenkinsci.plugins.workflow.steps.FlowInterruptedException
[2021-05-26T04:24:30.073Z] 	at org.jenkinsci.plugins.workflow.steps.TimeoutStepExecution.cancel(TimeoutStepExecution.java:165)
[2021-05-26T04:24:30.073Z] 	at org.jenkinsci.plugins.workflow.steps.TimeoutStepExecution.access$100(TimeoutStepExecution.java:38)
[2021-05-26T04:24:30.073Z] 	at org.jenkinsci.plugins.workflow.steps.TimeoutStepExecution$1.run(TimeoutStepExecution.java:139)
[2021-05-26T04:24:30.073Z] 	at jenkins.security.ImpersonatingScheduledExecutorService$1.run(ImpersonatingScheduledExecutorService.java:67)
[2021-05-26T04:24:30.073Z] 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[2021-05-26T04:24:30.073Z] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[2021-05-26T04:24:30.073Z] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[2021-05-26T04:24:30.073Z] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[2021-05-26T04:24:30.073Z] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[2021-05-26T04:24:30.073Z] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[2021-05-26T04:24:30.073Z] 	at java.lang.Thread.run(Thread.java:748)
[2021-05-26T04:24:30.073Z] 
[2021-05-26T04:24:30.152Z] Archiving artifacts
[2021-05-26T04:24:30.450Z] Failed in branch Linux
[2021-05-26T04:24:30.654Z] Stage "Release to feedz.io" skipped due to earlier failure(s)
[2021-05-26T04:24:30.741Z] Stage "Release" skipped due to earlier failure(s)
[2021-05-26T04:24:30.781Z] Stage "Release" skipped due to earlier failure(s)
[2021-05-26T04:24:30.868Z] Stage "Release" skipped due to earlier failure(s)
[2021-05-26T04:24:31.007Z] Stage "AfterRelease" skipped due to earlier failure(s)
[2021-05-26T04:24:31.041Z] Stage "AfterRelease" skipped due to earlier failure(s)
[2021-05-26T04:24:31.500Z] Running on Jenkins in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1288
[2021-05-26T04:24:31.597Z] [INFO] getVaultSecret: Getting secrets
[2021-05-26T04:24:31.665Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID
[2021-05-26T04:24:32.690Z] + chmod 755 generate-build-data.sh
[2021-05-26T04:24:32.690Z] + ./generate-build-data.sh https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1288/ https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1288/runs/8 FAILURE 7425486
[2021-05-26T04:24:32.690Z] INFO: curl https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1288/runs/8/steps/?limit=10000 -o steps-info.json
[2021-05-26T04:24:35.562Z] INFO: curl https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1288/runs/8/tests/?status=FAILED -o tests-errors.json
[2021-05-26T04:24:43.730Z] INFO: curl https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1288/runs/8/log/ -o pipeline-log.txt

@russcam russcam requested review from gregkalapos and bmorelli25 May 5, 2021 00:36
Copy link
Contributor

@gregkalapos gregkalapos left a comment

Choose a reason for hiding this comment

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

It looks ok to me, I had some questions below.

/// </summary>
internal class TraceLogger : IApmLogger, ILogLevelSwitchable
{
private const string SourceName = "Elastic.Apm";
Copy link
Contributor

Choose a reason for hiding this comment

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

Suggested change
private const string SourceName = "Elastic.Apm";
private const string _sourceName= "Elastic.Apm";


var message = formatter(state, e);

// default message size is 51 + length of loglevel (max 8), message and exception.
Copy link
Contributor

Choose a reason for hiding this comment

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

I don't really get this comment. What do you mean by "default message size is 51"?

Looking at the code I'd think that the strategy here is to start with a fairly small number for the capacity, but then ultimately the capacity of the StringBuilder will grow based on the length of the messages we print. So in this case we start with 80 (line below) and then if the message is longer then StringBuilder will increase the capacity and once we reuse it for a later massage the capacity will be bigger. So it'll adapt to the longest message. Do I understand this correctly?

What I wanna say here is that I don't really get the comment here :)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

It means that the complete log message size at a minimum will be 51 characters, plus the variable length of log level (max 8 characters), message and exception. So any starting capacity should at a minimum accommodate this, which the starting capacity of 80 characters will - assuming no exception and max log level length, leaves 21 characters for the message. This may be overly conservative, in which case a better estimate may be to use 59 + the calculated mean length of a log message.

StringBuilder will grow (and allocate) to accommodate larger log messages. The intention is to avoid allocating whilst serving the common usage.

Copy link
Contributor

Choose a reason for hiding this comment

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

Got it - the term default message size was strange to me, but I got it.

russcam added a commit to russcam/apm-agent-dotnet that referenced this pull request May 5, 2021
This commit removes the StringBuilderCache,
calculating a capacity for a StringBuilder from
the log component lengths.
@gregkalapos gregkalapos self-requested a review May 26, 2021 19:26
Copy link
Contributor

@gregkalapos gregkalapos left a comment

Choose a reason for hiding this comment

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

LGTM.

Would you mind documenting why you removed StringBuilderCache? I think it's fine and honestly I don't think it added much perf. improvement - I'm just curious why you ended up removing.

@russcam
Copy link
Contributor Author

russcam commented May 27, 2021

Removed StringBuilderCache for now in order to progress the PR. The approach would benefit from a benchmarking analysis to understand the impact that it could have in reducing allocations, but effort is focused on preparing a release.

@russcam russcam merged commit 3f9a734 into elastic:master May 27, 2021
@russcam russcam deleted the feature/tracelistener branch May 27, 2021 01:21
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)
  ...
russcam added a commit that referenced this pull request Jun 10, 2021
russcam added a commit that referenced this pull request Jun 10, 2021
Relates: #1288
(cherry picked from commit c9cb0e0)
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.

Default TraceListener based logger for ASP.NET Full Framework
3 participants