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

Breakdown metrics #1271

Merged
merged 30 commits into from
Jun 24, 2021
Merged

Breakdown metrics #1271

merged 30 commits into from
Jun 24, 2021

Conversation

gregkalapos
Copy link
Contributor

@gregkalapos gregkalapos commented Apr 21, 2021

Solves #227

image

TODOs:

  • Add docs
  • Test with non-sampled transactions update: not needed - non-sampled transactions and spans also generate these metrics - according to the spec that's preferred.
  • Disable breakdown metric collection

@apmmachine
Copy link
Contributor

apmmachine commented Apr 21, 2021

❕ Build Aborted

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

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

Expand to view the summary

Build stats

  • Build Cause: Pull request #1271 updated

  • Reason: Aborted from #50

  • Start Time: 2021-06-23T22:24:44.514+0000

  • Duration: 26 min 16 sec

  • Commit: 8af4861

Test stats 🧪

Test Results
Failed 3
Passed 8963
Skipped 83
Total 9049

Trends 🧪

Image of Build Times

Image of Tests

Test errors 3

Expand to view the tests failures

Initializing / Parallel / Windows .NET Core / Test / BreakdownTests.Elastic.Apm.Tests.BreakdownTests.TransactionWithSpans – Elastic.Apm.Tests.BreakdownTests
    Expand to view the error details

     Expected payloadSender.Metrics {Elastic.Apm.Metrics.MetricSet
       {
          Samples = {MetricSample{span.self_time.count: 1}, MetricSample{span.self_time.sum.us: 221225}}
          Span = Elastic.Apm.Metrics.SpanInfo
          {
             SubType = <null>
             Type = "app"
          }
          Timestamp = 1624488358908783L
          Transaction = Elastic.Apm.Metrics.TransactionInfo
          {
             Name = "Foo"
             Type = "Bar"
          }
       }} to have an item matching (((n Is MetricSet) AndAlso Convert(n, MetricSet).Span.Type.Equals("Bar2")) AndAlso IsNullOrEmpty(Convert(n, MetricSet).Span.SubType)). 
    

    Expand to view the stacktrace

     Expected payloadSender.Metrics {Elastic.Apm.Metrics.MetricSet
       {
          Samples = {MetricSample{span.self_time.count: 1}, MetricSample{span.self_time.sum.us: 221225}}
          Span = Elastic.Apm.Metrics.SpanInfo
          {
             SubType = <null>
             Type = "app"
          }
          Timestamp = 1624488358908783L
          Transaction = Elastic.Apm.Metrics.TransactionInfo
          {
             Name = "Foo"
             Type = "Bar"
          }
       }} to have an item matching (((n Is MetricSet) AndAlso Convert(n, MetricSet).Span.Type.Equals("Bar2")) AndAlso IsNullOrEmpty(Convert(n, MetricSet).Span.SubType)).
    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.Contain(Expression`1 predicate, String because, Object[] becauseArgs) in C:\projects\fluentassertions-vf06b\Src\FluentAssertions\Collections\SelfReferencingCollectionAssertions.cs:line 477
       at Elastic.Apm.Tests.BreakdownTests.TransactionWithSpans() in C:\Users\jenkins\workspace\net_apm-agent-dotnet-mbp_PR-1271\apm-agent-dotnet\test\Elastic.Apm.Tests\BreakdownTests.cs:line 70 
    

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

     Expected payloadSender.Metrics {Elastic.Apm.Metrics.MetricSet
       {
          Samples = {MetricSample{span.self_time.count: 1}, MetricSample{span.self_time.sum.us: 243394.99999999997}}
          Span = Elastic.Apm.Metrics.SpanInfo
          {
             SubType = <null>
             Type = "app"
          }
          Timestamp = 1624487985308886L
          Transaction = Elastic.Apm.Metrics.TransactionInfo
          {
             Name = "Foo"
             Type = "Bar"
          }
       }} to have an item matching (((n Is MetricSet) AndAlso Convert(n, MetricSet).Span.Type.Equals("Bar2")) AndAlso IsNullOrEmpty(Convert(n, MetricSet).Span.SubType)). 
    

    Expand to view the stacktrace

     Expected payloadSender.Metrics {Elastic.Apm.Metrics.MetricSet
       {
          Samples = {MetricSample{span.self_time.count: 1}, MetricSample{span.self_time.sum.us: 243394.99999999997}}
          Span = Elastic.Apm.Metrics.SpanInfo
          {
             SubType = <null>
             Type = "app"
          }
          Timestamp = 1624487985308886L
          Transaction = Elastic.Apm.Metrics.TransactionInfo
          {
             Name = "Foo"
             Type = "Bar"
          }
       }} to have an item matching (((n Is MetricSet) AndAlso Convert(n, MetricSet).Span.Type.Equals("Bar2")) AndAlso IsNullOrEmpty(Convert(n, MetricSet).Span.SubType)).
    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.Collections.SelfReferencingCollectionAssertions`2.Contain(Expression`1 predicate, String because, Object[] becauseArgs)
       at Elastic.Apm.Tests.BreakdownTests.TransactionWithSpans() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1271/apm-agent-dotnet/test/Elastic.Apm.Tests/BreakdownTests.cs:line 70 
    

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

     Expected payloadSender.Metrics {Elastic.Apm.Metrics.MetricSet
       {
          Samples = {MetricSample{span.self_time.count: 1}, MetricSample{span.self_time.sum.us: 191367.00000000003}}
          Span = Elastic.Apm.Metrics.SpanInfo
          {
             SubType = <null>
             Type = "Bar"
          }
          Timestamp = 1624488115896986L
          Transaction = Elastic.Apm.Metrics.TransactionInfo
          {
             Name = "Foo"
             Type = "Bar"
          }
       }} to have an item matching (((n Is MetricSet) AndAlso Convert(n, MetricSet).Span.Type.Equals("Bar2")) AndAlso IsNullOrEmpty(Convert(n, MetricSet).Span.SubType)). 
    

    Expand to view the stacktrace

     Expected payloadSender.Metrics {Elastic.Apm.Metrics.MetricSet
       {
          Samples = {MetricSample{span.self_time.count: 1}, MetricSample{span.self_time.sum.us: 191367.00000000003}}
          Span = Elastic.Apm.Metrics.SpanInfo
          {
             SubType = <null>
             Type = "Bar"
          }
          Timestamp = 1624488115896986L
          Transaction = Elastic.Apm.Metrics.TransactionInfo
          {
             Name = "Foo"
             Type = "Bar"
          }
       }} to have an item matching (((n Is MetricSet) AndAlso Convert(n, MetricSet).Span.Type.Equals("Bar2")) AndAlso IsNullOrEmpty(Convert(n, MetricSet).Span.SubType)).
    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.Collections.SelfReferencingCollectionAssertions`2.Contain(Expression`1 predicate, String because, Object[] becauseArgs)
       at Elastic.Apm.Tests.BreakdownTests.TransactionWithSpans() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1271/apm-agent-dotnet/test/Elastic.Apm.Tests/BreakdownTests.cs:line 70 
    

Steps errors 4

Expand to view the steps failures

Archive the artifacts
  • Took 0 min 0 sec . View more details on here
  • Description: [2021-06-23T22:50:59.311Z] Archiving artifacts withAzureCredentials: error org.jenkinsci.plugins.wo
Build
  • Took 1 min 36 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-06-23T22:49:31.378Z] 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-06-23T22:50:36.948Z] Copied Logging/TraceLogger.cs. 
[2021-06-23T22:50:36.948Z] Starting copy source file Elastic.Apm/Api/Destination.cs. 
[2021-06-23T22:50:37.018Z] Copied Elastic.Apm/Api/Destination.cs. 
[2021-06-23T22:50:37.019Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Serialization/JsonDictionaryContract.cs. 
[2021-06-23T22:50:37.186Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Serialization/JsonDictionaryContract.cs. 
[2021-06-23T22:50:37.186Z] Starting copy source file Libraries/Newtonsoft.Json/Utilities/CollectionWrapper.cs. 
[2021-06-23T22:50:37.257Z] Copied Libraries/Newtonsoft.Json/Utilities/CollectionWrapper.cs. 
[2021-06-23T22:50:37.257Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Utilities/NullableAttributes.cs. 
[2021-06-23T22:50:37.330Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Utilities/NullableAttributes.cs. 
[2021-06-23T22:50:37.330Z] Starting copy source file Api/Label.cs. 
[2021-06-23T22:50:37.412Z] Copied Api/Label.cs. 
[2021-06-23T22:50:37.413Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Linq/JValue.Async.cs. 
[2021-06-23T22:50:37.483Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Linq/JValue.Async.cs. 
[2021-06-23T22:50:37.483Z] Starting copy source file Elastic.Apm/ServerInfo/ApmServerInfoProvider.cs. 
[2021-06-23T22:50:37.554Z] Copied Elastic.Apm/ServerInfo/ApmServerInfoProvider.cs. 
[2021-06-23T22:50:37.554Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Serialization/JsonSerializerInternalBase.cs. 
[2021-06-23T22:50:37.624Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Serialization/JsonSerializerInternalBase.cs. 
[2021-06-23T22:50:37.625Z] Starting copy source file Helpers/ExceptionUtils.cs. 
[2021-06-23T22:50:37.703Z] Copied Helpers/ExceptionUtils.cs. 
[2021-06-23T22:50:37.703Z] Starting copy source file Libraries/Newtonsoft.Json/Linq/JProperty.cs. 
[2021-06-23T22:50:37.779Z] Copied Libraries/Newtonsoft.Json/Linq/JProperty.cs. 
[2021-06-23T22:50:37.779Z] Starting copy source file Libraries/Newtonsoft.Json/Utilities/DictionaryWrapper.cs. 
[2021-06-23T22:50:37.859Z] Copied Libraries/Newtonsoft.Json/Utilities/DictionaryWrapper.cs. 
[2021-06-23T22:50:37.859Z] Starting copy source file Elastic.Apm.AspNetCore/Extensions/StringExtensions.cs. 
[2021-06-23T22:50:37.929Z] Copied Elastic.Apm.AspNetCore/Extensions/StringExtensions.cs. 
[2021-06-23T22:50:37.929Z] Starting copy source file Elastic.Apm/Api/SpanCount.cs. 
[2021-06-23T22:50:38.000Z] Copied Elastic.Apm/Api/SpanCount.cs. 
[2021-06-23T22:50:38.000Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Linq/JsonPath/FieldMultipleFilter.cs. 
[2021-06-23T22:50:38.075Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Linq/JsonPath/FieldMultipleFilter.cs. 
[2021-06-23T22:50:38.075Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Utilities/ReflectionDelegateFactory.cs. 
[2021-06-23T22:50:38.144Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Utilities/ReflectionDelegateFactory.cs. 
[2021-06-23T22:50:38.144Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Serialization/JsonSerializerProxy.cs. 
[2021-06-23T22:50:38.214Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Serialization/JsonSerializerProxy.cs. 
[2021-06-23T22:50:38.214Z] Starting copy source file Libraries/Newtonsoft.Json/Utilities/EnumInfo.cs. 
[2021-06-23T22:50:38.282Z] Copied Libraries/Newtonsoft.Json/Utilities/EnumInfo.cs. 
[2021-06-23T22:50:38.282Z] Starting copy source file Elastic.Apm/Libraries/Ben.Demystifier/TypeNameHelper.cs. 
[2021-06-23T22:50:38.351Z] Copied Elastic.Apm/Libraries/Ben.Demystifier/TypeNameHelper.cs. 
[2021-06-23T22:50:38.351Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/JsonSerializationException.cs. 
[2021-06-23T22:50:38.421Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/JsonSerializationException.cs. 
[2021-06-23T22:50:38.421Z] Starting copy source file Elastic.Apm/ServerInfo/ApmServerInfo.cs. 
[2021-06-23T22:50:38.489Z] Copied Elastic.Apm/ServerInfo/ApmServerInfo.cs. 
[2021-06-23T22:50:38.489Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Converters/XmlNodeConverter.cs. 
[2021-06-23T22:50:38.586Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Converters/XmlNodeConverter.cs. 
[2021-06-23T22:50:38.586Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Schema/ValidationEventArgs.cs. 
[2021-06-23T22:50:38.654Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Schema/ValidationEventArgs.cs. 
[2021-06-23T22:50:38.654Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Converters/StringEnumConverter.cs. 
[2021-06-23T22:50:38.725Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Converters/StringEnumConverter.cs. 
[2021-06-23T22:50:38.725Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Utilities/DynamicProxyMetaObject.cs. 
[2021-06-23T22:50:38.798Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Utilities/DynamicProxyMetaObject.cs. 
[2021-06-23T22:50:38.798Z] Starting copy source file Libraries/Newtonsoft.Json/Converters/StringEnumConverter.cs. 
[2021-06-23T22:50:38.871Z] Copied Libraries/Newtonsoft.Json/Converters/StringEnumConverter.cs. 
[2021-06-23T22:50:38.871Z] Starting copy source file Libraries/Newtonsoft.Json/Serialization/JsonPrimitiveContract.cs. 
[2021-06-23T22:50:38.942Z] Copied Libraries/Newtonsoft.Json/Serialization/JsonPrimitiveContract.cs. 
[2021-06-23T22:50:38.942Z] Starting copy source file Elastic.Apm/Config/AbstractConfigurationReader.cs. 
[2021-06-23T22:50:39.025Z] Copied Elastic.Apm/Config/AbstractConfigurationReader.cs. 
[2021-06-23T22:50:39.025Z] Starting copy source file Elastic.Apm/Filters/SpanStackTraceCapturingFilter.cs. 
[2021-06-23T22:50:39.098Z] Copied Elastic.Apm/Filters/SpanStackTraceCapturingFilter.cs. 
[2021-06-23T22:50:39.098Z] Starting copy source file Elastic.Apm/Helpers/ContractExtensions.cs. 
[2021-06-23T22:50:39.167Z] Copied Elastic.Apm/Helpers/ContractExtensions.cs. 
[2021-06-23T22:50:39.167Z] Starting copy source file Libraries/Newtonsoft.Json/Schema/JsonSchemaBuilder.cs. 
[2021-06-23T22:50:39.241Z] Copied Libraries/Newtonsoft.Json/Schema/JsonSchemaBuilder.cs. 
[2021-06-23T22:50:39.241Z] Starting copy source file Report/Serialization/MetricSetConverter.cs. 
[2021-06-23T22:50:39.309Z] Copied Report/Serialization/MetricSetConverter.cs. 
[2021-06-23T22:50:39.309Z] Starting copy source file Libraries/Newtonsoft.Json/Utilities/DynamicProxy.cs. 
[2021-06-23T22:50:39.378Z] Copied Libraries/Newtonsoft.Json/Utilities/DynamicProxy.cs. 
[2021-06-23T22:50:39.378Z] Starting copy source file Cloud/AzureCloudMetadataProvider.cs. 
[2021-06-23T22:50:39.450Z] Copied Cloud/AzureCloudMetadataProvider.cs. 
[2021-06-23T22:50:39.451Z] Starting copy source file Api/Context.cs. 
[2021-06-23T22:50:39.526Z] Copied Api/Context.cs. 
[2021-06-23T22:50:39.526Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Serialization/DefaultContractResolver.cs. 
[2021-06-23T22:50:39.617Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Serialization/DefaultContractResolver.cs. 
[2021-06-23T22:50:39.617Z] Starting copy source file Elastic.Apm/Logging/LogValuesFormatter.cs. 
[2021-06-23T22:50:39.689Z] Copied Elastic.Apm/Logging/LogValuesFormatter.cs. 
[2021-06-23T22:50:39.689Z] Starting copy source file Config/AbstractConfigurationReader.cs. 
[2021-06-23T22:50:39.770Z] Copied Config/AbstractConfigurationReader.cs. 
[2021-06-23T22:50:57.468Z] [Checks API] No suitable checks publisher found.
[2021-06-23T22:50:57.558Z] [INFO] getVaultSecret: Getting secrets
[2021-06-23T22:50:57.598Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID
[2021-06-23T22:50:57.905Z] Running in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1271/apm-agent-dotnet
[2021-06-23T22:50:57.924Z] [INFO] Codecov: Getting branch ref...
[2021-06-23T22:50:57.997Z] Masking supported pattern matches of $GITHUB_TOKEN
[2021-06-23T22:50:58.512Z] [INFO] Codecov: Sending data...
[2021-06-23T22:50:58.894Z] + echo curl -sSLo codecov.sh https://codecov.io/bash
[2021-06-23T22:50:58.895Z] curl -sSLo codecov.sh https://codecov.io/bash
[2021-06-23T22:50:59.213Z] + echo bash codecov.sh
[2021-06-23T22:50:59.213Z] bash codecov.sh
[2021-06-23T22:50:59.311Z] Archiving artifacts
[2021-06-23T22:50:59.393Z] Failed in branch Linux
[2021-06-23T22:50:59.479Z] Stage "Release to feedz.io" skipped due to earlier failure(s)
[2021-06-23T22:50:59.518Z] Stage "Release" skipped due to earlier failure(s)
[2021-06-23T22:50:59.535Z] Stage "Release" skipped due to earlier failure(s)
[2021-06-23T22:50:59.576Z] Stage "Release" skipped due to earlier failure(s)
[2021-06-23T22:50:59.641Z] Stage "AfterRelease" skipped due to earlier failure(s)
[2021-06-23T22:50:59.658Z] Stage "AfterRelease" skipped due to earlier failure(s)
[2021-06-23T22:51:00.088Z] Running on Jenkins in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1271
[2021-06-23T22:51:00.137Z] [INFO] getVaultSecret: Getting secrets
[2021-06-23T22:51:00.179Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID
[2021-06-23T22:51:00.862Z] + chmod 755 generate-build-data.sh
[2021-06-23T22:51:00.868Z] + ./generate-build-data.sh https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1271/ https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1271/runs/49 ABORTED 1576084
[2021-06-23T22:51:00.868Z] INFO: curl https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1271/runs/49/steps/?limit=10000 -o steps-info.json

@bluetentacle
Copy link

What's the status of this PR?

@gregkalapos gregkalapos self-assigned this May 26, 2021

[float]
[[metrics-application]]
=== Built-in application metrics
Copy link
Contributor Author

Choose a reason for hiding this comment

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

100% stolen from the java docs.

@gregkalapos gregkalapos requested a review from russcam May 26, 2021 21:45
@gregkalapos gregkalapos marked this pull request as ready for review May 26, 2021 21:45
@gregkalapos
Copy link
Contributor Author

What's the status of this PR?

Ready for review.

@gregkalapos
Copy link
Contributor Author

Pushed a few small changes:

  • After asking around I learned that the duration of spans with type: "app" needs to be handled as part of the transaction self-time duration, I adapted the code according to this and added tests.
  • Rebased on master.

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.

Left some initial comments to discuss


Fields:

* `sum.us`: The sum of all transaction durations in ms since the last report (the delta)
Copy link
Contributor

Choose a reason for hiding this comment

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

More an observation:

The field used is sum.us - is the u in .us intended to be μ (mu)? If so, μs is the unit for microseconds, but the description says ms, milliseconds. Is that correct?

Copy link
Contributor Author

@gregkalapos gregkalapos Jun 14, 2021

Choose a reason for hiding this comment

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

Hahh - I looked into this and indeed there was an issue here.

is the u in .us intended to be μ (mu)?

Yes!

but the description says ms, milliseconds. Is that correct?

No, it wasn't. This was a copy from the java agent docs, and in fact we sent the data in milliseconds in the PR originally. I looked into more docs and this clearly should be microseconds (e.g. the Go agent docs has this correctly). I fixed the code, so now we send it in microseconds and I also fixed this part of the doc as well - all microseconds now.

Side-note: since the breakdown metrics are used to calculate the time spent in different span types by percentage, I think the unit will not break the feature as long as all the data is in the same unit (which was the case), so likely that's why it was not an issue before - it'd be nice to see if all agents send it in the correct unit :)


Fields:

* `sum.us`: The sum of all span self-times in ms since the last report (the delta)
Copy link
Contributor

Choose a reason for hiding this comment

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

Same observation as above:

The field used is sum.us - is the u in .us intended to be μ (mu)? If so, μs is the unit for microseconds, but the description says ms, milliseconds. Is that correct?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Same as above.

@AlexanderWert AlexanderWert linked an issue Jun 10, 2021 that may be closed by this pull request
19 tasks
@gregkalapos gregkalapos requested a review from russcam June 14, 2021 20:59
@gregkalapos
Copy link
Contributor Author

Rebased, ready to another review round.

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.

I've gone through in some more detail.

The gathering of breakdown metrics looks like it could be performed in PayloadSenderV2, when the transaction is queued. PayloadSenderV2 would take BreakdownMetricsProvider in its ctor. I know I previously suggested hooking into the .Ended event as has been done here, but in retrospect, performing in PayloadSenderV2 would actually be cleaner.

An aside-

PayloadSenderV2 is a little bit of a misnomer as its performing a few different functions:

  1. holding a queue of items to send to APM server
  2. filtering items that should be sent
  3. serializing items to be sent
  4. actually sending items to APM server

Might be useful to refactor this in the next major version.


internal readonly TraceState _traceState;

internal readonly ConcurrentDictionary<(string, string), SpanTimer> SpanTimings = new();
Copy link
Contributor

Choose a reason for hiding this comment

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

Introducing a type for the key would make it clear what each part of the tuple relates to

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Done

{
if (item != null)
{
if (!WildcardMatcher.IsAnyMatch(currentConfigSnapshot.DisableMetrics, BreakdownMetricsProvider.SpanSelfTime))
Copy link
Contributor

Choose a reason for hiding this comment

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

This makes the assumption that any added metrics providers should be controlled by the span self-time metric. Whilst this holds true now as breakdown provider is the only one added in the ctor, maybe the string(s) to match should be a property on an IMetricsProvider to allow each individual provider determine if it should be added.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Yeah, I agree that this isn't ok.

maybe the string(s) to match should be a property on an IMetricsProvider to allow each individual provider determine if it should be added.

Problem is we'd need to address 2 scenarios with this:

  • The BreakdownMetricsProvider and everything passed to the ctor is already created - so yes, in that case we could just query the string(s) from IMetricsProvider and it'd indeed help.
  • Every other IMetricsProvider is not instantiated at this point, so we can't query the string(s) list for those. In that cases what we do is that we check the DisabledMetrics list and if one of those is disabled we don't even instantiate those.

What I did is that I moved the check to AgentCompontents - that's where we instantiate the BreakdownMetricsProvider.

Long term we could come up with an infrastructure to better handle this - I think it'd be fine to introduce the string list you suggest, but that'll also mean we'd need to instantiate all the IMetricsProvider and if they are not enabled based on the string(s) list, we'd just not add them to the list and let them GCed. Nevertheless that'd be a longer discussion, so maybe we could do that in a separate PR.

Copy link
Contributor Author

@gregkalapos gregkalapos Jun 15, 2021

Choose a reason for hiding this comment

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

Update: I decided to move on and implement it nevertheless. I added IMetricsProvider.IsEnabled - so we instantiate each IMetricsProvider implementation, but only add them if they are enabled. This changed a few things around metrics collection, but in my opinion this is now much cleaner - checks if a specific IMetricsProvider is enabled is now the same for all IMetricsProvider implementations and we also got rid of the huge checks in MetricsCollector.ctor - instead now IMetricsProvider do the check for themselves.

Copy link
Contributor

Choose a reason for hiding this comment

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

++ it'd be possible to build on this for the custom metrics scenarios.

@gregkalapos
Copy link
Contributor Author

gregkalapos commented Jun 15, 2021

I've gone through in some more detail.

The gathering of breakdown metrics looks like it could be performed in PayloadSenderV2, when the transaction is queued. PayloadSenderV2 would take BreakdownMetricsProvider in its ctor. I know I previously suggested hooking into the .Ended event as has been done here, but in retrospect, performing in PayloadSenderV2 would actually be cleaner.

There are multiple places where we can capture the metrics - basically anything works after the transaction ends and before it goes out to APM server.

In what sense do you think it would be cleaner?

I think it's worth looking at how data flows.

In the PR currently:
Tracer creates the metrics -> BreakdownMetricsProvider -> MetricsCollector -> PayloadSenderV2 -> APM Server

If we move it to PayloadSenderV2, it'd be basically:
PayloadSenderV2 -> BreakdownMetricsProvider -> MetricsCollector -> PayloadSenderV2 -> APM Server

which to me doesn't sound ok. And PayloadSenderV2 can't just keep those metrics, since it's like any other metric, so we need to honor the metric interval setting and we should send those in batches, all that infrastructure is already implemented in MetricsCollector. Going from PayloadSenderV2 to MetricsCollector and then again to PayloadSenderV2 is odd.

Some other issues:

  • PayloadSenderV2 is not a component to create metrics, it's to send the payload.
  • If someone replaces it (which is super rare, but I saw some people doing it), they won't have breakdown metrics anymore - which to me makes putting it into PayloadSenderV2 not clean. If I replace the payload sender, I'd not expect that affecting breakdown metric collection. Same applies for us: let's say we implement a new payload sender - why does it need to change breakdown metrics collection as well?
  • The breakdown metrics are emitted by transactions - it's defined to be emitted when the transaction finishes, so I think the closer it is to Transaction.End(), the better - yes, Transaction.End() directly calls PayloadSenderV2, but that is a different component for different purposes.
  • If transactions emit the metrics, testing is also very natural - no additional config is needed. If we move it into PayloadSenderV2, we'll need to inject a BreakdownMetricsProvider into our test payload sender. This is not the end of the world, but again raises the question: why does the payload sender influence breakdown metrics collection, which is a metric purely based on transactions (and spans)?

I opened #1341 which moves BreakdownMetricsProvider to PayloadSenderV2. Overall I think the PR in its current form is better. If it's ok for you I'd leave it out, if not I'll cherry pick the commit that moved BreakdownMetricsProvider to PaylaadSenderV2.

Otherwise it's ready for another round.

@gregkalapos gregkalapos requested a review from russcam June 15, 2021 21:50
@russcam
Copy link
Contributor

russcam commented Jun 16, 2021

In what sense do you think it would be cleaner?

  1. It avoids the creation and invocation of an event delegate for each transaction, to capture breakdown metrics
  2. Breakdown metrics could be captured on the dedicated payload processing thread

The transaction.Ended event has a valid use case in scenarios where some integration outside of Elastic.Apm needs to be notified when a transaction ends, such as in StackExchange.Redis, but doesn't have to be used for breakdown metrics, which are calculated in Elastic.Apm.

  • PayloadSenderV2 is not a component to create metrics, it's to send the payload.

It's doing a lot more than sending payloads; it's more of a processing pipeline for payloads, which could also include calculating breakdown metrics for a particular payload, transactions.

  • If someone replaces it (which is super rare, but I saw some people doing it), they won't have breakdown metrics anymore - which to me makes putting it into PayloadSenderV2 not clean. If I replace the payload sender, I'd not expect that affecting breakdown metric collection. Same applies for us: let's say we implement a new payload sender - why does it need to change breakdown metrics collection as well?

If someone replaces IPayloadSender, the same holds true for

  1. transaction, span and error filtering
  2. enqueuing payloads and processing on a configurable interval on a dedicated thread
  3. sending payloads to APM server

but the public interface doesn't define a contract for this behaviour, only that payloads are queued

public interface IPayloadSender
{
	void QueueError(IError error);
	void QueueMetrics(IMetricSet metrics);
	void QueueSpan(ISpan span);
	void QueueTransaction(ITransaction transaction);
}

I'm trying to think about the architecture of the agent in terms of how it is evolving and where we might want to go with it. Happy to discuss here, though it might be easier to chat over zoom 😃


_logger.Debug()?.Log("Starting {TransactionValue}", retVal);
return retVal;

void RetValOnEnded(object sender, EventArgs e)
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: naming

Suggested change
void RetValOnEnded(object sender, EventArgs e)
void CaptureBreakdownMetrics(object sender, EventArgs e)

Copy link
Contributor Author

@gregkalapos gregkalapos Jun 16, 2021

Choose a reason for hiding this comment

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

This part got removed.


public IEnumerable<MetricSet> GetSamples()
{
var retVal = new List<MetricSet>();
Copy link
Contributor

Choose a reason for hiding this comment

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

could avoid resizing the internal array by allocating a capacity based on count of _itemsToSend (or 1000)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Yes, makes sense - done.

lock (_lock)
{
retVal.AddRange(_itemsToSend.Take(1000));
_itemsToSend.Clear();
Copy link
Contributor

Choose a reason for hiding this comment

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

should _itemsToSend be cleared? What if it still contains items to send after taking 1000?

Copy link
Contributor Author

@gregkalapos gregkalapos Jun 16, 2021

Choose a reason for hiding this comment

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

should _itemsToSend be cleared? What if it still contains items to send after taking 1000?

The spec says: "...agents must cap the total number of metricsets. A reasonable default seems to be [1000]. When the limit is reached, agents should log sla warning...". So my understanding is that everything above 1k should be thrown away, so it's fine to clear those. Also worth noting that in this case we'd try to show time spent in percentage across 1K groups, so at this point I'd say the visualization can be also challenging depending on the distribution.

On the other hand by thinking about this: we should not even collect those in _itemsToSend, plus the warning was also missing. So I moved the handling of this into CaptureTransaction(Transaction): we only collect up to 1K items and if 1K is reached we log.

I also included a test to cover this.

/// <summary>
/// Encapsulates type and subtype
/// </summary>
internal struct SpanTypeAndSubtype
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: naming

Suggested change
internal struct SpanTypeAndSubtype
internal struct SpanTimerKey

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Done.

@gregkalapos
Copy link
Contributor Author

In what sense do you think it would be cleaner?

  1. It avoids the creation and invocation of an event delegate for each transaction, to capture breakdown metrics
  2. Breakdown metrics could be captured on the dedicated payload processing thread

The transaction.Ended event has a valid use case in scenarios where some integration outside of Elastic.Apm needs to be notified when a transaction ends, such as in StackExchange.Redis, but doesn't have to be used for breakdown metrics, which are calculated in Elastic.Apm.

  1. I agree the delegate is not optimal for that. So far we had 3 options: 1) doing it in transaction 2) doing it in tracer 3) doing it in payload sender. Option 1 (the original code) would not have this issue and I think it's more natural.
  2. That's true for creating the MetricSet, but not true for all the calculation. Also, this'd only apply to this single metric, but not for the other. If this is a goal (which I think in this PR should not be) then we should make a dedicated thread for all metrics collection.
  • PayloadSenderV2 is not a component to create metrics, it's to send the payload.

It's doing a lot more than sending payloads; it's more of a processing pipeline for payloads, which could also include calculating breakdown metrics for a particular payload, transactions.

That's true and everyone (rightfully) criticises it, yet we end up putting more stuff into it. So this is again a reason why I'd not put it into there - but the main reason I would not put it there is that I think breakdown metrics creation is really not the job for the payload sender.

  • If someone replaces it (which is super rare, but I saw some people doing it), they won't have breakdown metrics anymore - which to me makes putting it into PayloadSenderV2 not clean. If I replace the payload sender, I'd not expect that affecting breakdown metric collection. Same applies for us: let's say we implement a new payload sender - why does it need to change breakdown metrics collection as well?

If someone replaces IPayloadSender, the same holds true for

  1. transaction, span and error filtering
  2. enqueuing payloads and processing on a configurable interval on a dedicated thread
  3. sending payloads to APM server

but the public interface doesn't define a contract for this behaviour, only that payloads are queued

public interface IPayloadSender
{
	void QueueError(IError error);
	void QueueMetrics(IMetricSet metrics);
	void QueueSpan(ISpan span);
	void QueueTransaction(ITransaction transaction);
}

That's true and unfortunate, but why do we need to make yet another component part of this list? I still don't see how it's related to payload sender. Breakdown is a metric created by spans and transactions.

I'm trying to think about the architecture of the agent in terms of how it is evolving and where we might want to go with it. Happy to discuss here, though it might be easier to chat over zoom 😃

Ok, let's zoom - maybe I just don't get the core of your motivation. I think the cleanest and simplest was to just call BreakdownMetricsProvider?.CaptureTransaction(Transaction) from Transaction.End() right after we create the last breakdown metric for the transaction. And I feel that holds true regardless of how future payloadsenders may look. But let's zoom...

@gregkalapos
Copy link
Contributor Author

In what sense do you think it would be cleaner?

  1. It avoids the creation and invocation of an event delegate for each transaction, to capture breakdown metrics
  2. Breakdown metrics could be captured on the dedicated payload processing thread

The transaction.Ended event has a valid use case in scenarios where some integration outside of Elastic.Apm needs to be notified when a transaction ends, such as in StackExchange.Redis, but doesn't have to be used for breakdown metrics, which are calculated in Elastic.Apm.

  1. I agree the delegate is not optimal for that. So far we had 3 options: 1) doing it in transaction 2) doing it in tracer 3) doing it in payload sender. Option 1 (the original code) would not have this issue and I think it's more natural.
  2. That's true for creating the MetricSet, but not true for all the calculation. Also, this'd only apply to this single metric, but not for the other. If this is a goal (which I think in this PR should not be) then we should make a dedicated thread for all metrics collection.
  • PayloadSenderV2 is not a component to create metrics, it's to send the payload.

It's doing a lot more than sending payloads; it's more of a processing pipeline for payloads, which could also include calculating breakdown metrics for a particular payload, transactions.

That's true and everyone (rightfully) criticises it, yet we end up putting more stuff into it. So this is again a reason why I'd not put it into there - but the main reason I would not put it there is that I think breakdown metrics creation is really not the job for the payload sender.

  • If someone replaces it (which is super rare, but I saw some people doing it), they won't have breakdown metrics anymore - which to me makes putting it into PayloadSenderV2 not clean. If I replace the payload sender, I'd not expect that affecting breakdown metric collection. Same applies for us: let's say we implement a new payload sender - why does it need to change breakdown metrics collection as well?

If someone replaces IPayloadSender, the same holds true for

  1. transaction, span and error filtering
  2. enqueuing payloads and processing on a configurable interval on a dedicated thread
  3. sending payloads to APM server

but the public interface doesn't define a contract for this behaviour, only that payloads are queued

public interface IPayloadSender
{
	void QueueError(IError error);
	void QueueMetrics(IMetricSet metrics);
	void QueueSpan(ISpan span);
	void QueueTransaction(ITransaction transaction);
}

That's true and unfortunate, but why do we need to make yet another component part of this list? I still don't see how it's related to payload sender. Breakdown is a metric created by spans and transactions.

I'm trying to think about the architecture of the agent in terms of how it is evolving and where we might want to go with it. Happy to discuss here, though it might be easier to chat over zoom 😃

Ok, let's zoom - maybe I just don't get the core of your motivation. I think the cleanest and simplest was to just call BreakdownMetricsProvider?.CaptureTransaction(Transaction) from Transaction.End() right after we create the last breakdown metric for the transaction. And I feel that holds true regardless of how future payloadsenders may look. But let's zoom...

Zoom summary: we agreed to move BreakdownMetricsProvider.CaptureTransaction() to Transaction.cs - I implemented that.

@gregkalapos gregkalapos requested a review from russcam June 16, 2021 19:58
@@ -20,7 +20,10 @@ internal class MockPayloadSender : IPayloadSender
{
private readonly List<IError> _errors = new List<IError>();
private readonly List<Func<IError, IError>> _errorFilters = new List<Func<IError, IError>>();
private readonly object _lock = new object();
private readonly object _spanLock = new object();
Copy link
Contributor Author

Choose a reason for hiding this comment

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

I saw tests failing with such logs - this specific test was a new one which I introduced in the PR. I wasn't able to repro this locally:

System.ArgumentException : Destination array was not long enough. Check the destination index, length, and the array's lower bounds.
Parameter name: destinationArray
Stacktrace
System.ArgumentException : Destination array was not long enough. Check the destination index, length, and the array's lower bounds.
Parameter name: destinationArray
Stack Trace:
   at System.Array.Copy(Array sourceArray, Int32 sourceIndex, Array destinationArray, Int32 destinationIndex, Int32 length, Boolean reliable)
   at System.Collections.Generic.List`1.CopyTo(T[] array, Int32 arrayIndex)
   at System.Collections.Generic.List`1..ctor(IEnumerable`1 collection)
   at Elastic.Apm.Tests.BreakdownTests.TransactionWithSpans() in C:\Users\jenkins\workspace\net_apm-agent-dotnet-mbp_PR-1271\apm-agent-dotnet\test\Elastic.Apm.Tests\BreakdownTests.cs:line 62

This exception isn't new - I already saw it on failing tests. I think the root cause of those failing tests is that the agent still puts an event into the MockPayloadSender while it makes the copy of the list. To address this I introduced locks in the MockPayloadSender.

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.

Left a comment around locking, rest looks OK.

}
else
{
var stopWatch = Stopwatch.StartNew();
while (_transactions.Count < count && signalled)
lock (_transactionLock)
Copy link
Contributor

Choose a reason for hiding this comment

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

If I understand this correctly, the lock around waiting for x count of transactions can't succeed because adding transactions is also within a lock, meaning no transactions can be added whilst waiting for the count to be reached.

I think the locks around WaitForX() count can be removed, and that locking is needed only on adding items or copying to an immutable collection.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Oh, there is an AutoResetEvent.WaitOne() within the lock 🤦 . I really wonder why no test failed, everything was green both locally and in CI. Yeah, I also think this should fail if first thread calls WaitForX() and then another one tries to add to the queue.

I think locking on the reading of _transaction.Count and spans.Count is needed - otherwise the number which the thread calling WaitForX() sees can be incorrect if another thread adds to the queue, but the lock should be limited to the call to .Count, and that finishes immediately.

I updated the PR accordingly.

@gregkalapos gregkalapos merged commit 07a4484 into elastic:master Jun 24, 2021
@gregkalapos gregkalapos deleted the BreakdownMetrics branch June 24, 2021 00:03
@apmmachine
Copy link
Contributor

💔 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 #1271 updated

  • Start Time: 2021-06-23T23:32:33.235+0000

  • Duration: 50 min 51 sec

  • Commit: 520d06f

Test stats 🧪

Test Results
Failed 2
Passed 19516
Skipped 122
Total 19640

Trends 🧪

Image of Build Times

Image of Tests

Test errors 2

Expand to view the tests failures

Initializing / Parallel / Windows .NET Framework / Test / CentralConfigFetcherTests.Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests.Should_Update_IgnoreMessageQueues_Configuration – Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests
    Expand to view the error details

     Expected collection not to be empty. 
    

    Expand to view the stacktrace

     Expected collection not to be empty.
    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.Collections.CollectionAssertions`2.NotBeEmpty(String because, Object[] becauseArgs)
       at Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests.Should_Update_IgnoreMessageQueues_Configuration()
    Standard Output:
        Elastic APM .NET Tests> 312> Xunit> [2021-06-23 23:58:53.029 +00:00][Info] - {LoggingTestBase} Starting test: Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests.Should_Update_IgnoreMessageQueues_Configuration...
        Elastic APM .NET Tests> 312> Xunit> [2021-06-23 23:58:53.041 +00:00][Error] - {CentralConfigFetcher} Exception was thrown while fetching configuration from APM Server and parsing it. ETag: `<null>'. URL: `http://localhost:8200/config/v1/agents?service.name=xunit_execution_desktop'. Apm Server base URL: `http://localhost:8200/'. WaitInterval: 5m. dbgIterationsCount: 1.
        Elastic APM .NET Tests> 312> Xunit> +-> Request:
        Elastic APM .NET Tests> 312> Xunit>     Method: GET, RequestUri: 'http://localhost:8200/config/v1/agents?service.name=xunit_execution_desktop', Version: 1.1, Content: <null>, Headers:
        Elastic APM .NET Tests> 312> Xunit>     {
        Elastic APM .NET Tests> 312> Xunit>       User-Agent: elasticapm-dotnet/1.10.0+520d06f38e81f908316329612d6d08a058c36964
        Elastic APM .NET Tests> 312> Xunit>       User-Agent: System.Net.Http/4.8.3761.0
        Elastic APM .NET Tests> 312> Xunit>       User-Agent: .NET_Framework/4.8.4300.0
        Elastic APM .NET Tests> 312> Xunit>     }
        Elastic APM .NET Tests> 312> Xunit> +-> Response:
        Elastic APM .NET Tests> 312> Xunit>     StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.StringContent, Headers:
        Elastic APM .NET Tests> 312> Xunit>     {
        Elastic APM .NET Tests> 312> Xunit>       ETag: "etag"
        Elastic APM .NET Tests> 312> Xunit>       Content-Type: text/plain; charset=utf-8
        Elastic APM .NET Tests> 312> Xunit>       Content-Length: 34
        Elastic APM .NET Tests> 312> Xunit>     }
        Elastic APM .NET Tests> 312> Xunit> +-> Response body [length: 34]:
        Elastic APM .NET Tests> 312> Xunit>     { "ignore_message_queues": "foo" }
        Elastic APM .NET Tests> 312> Xunit> +-> Exception: System.NullReferenceException: Object reference not set to an instance of an object.
        Elastic APM .NET Tests> 312> Xunit>    at Elastic.Apm.BackendComm.CentralConfig.CentralConfigFetcher.<WorkLoopIteration>d__15.MoveNext() in C:\Users\jenkins\workspace\net_apm-agent-dotnet-mbp_PR-1271\apm-agent-dotnet\src\Elastic.Apm\BackendComm\CentralConfig\CentralConfigFetcher.cs:line 107
        Elastic APM .NET Tests> 312> Xunit> [2021-06-23 23:59:53.128 +00:00][Info] - {LoggingTestBase} Finished test: Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests.Should_Update_IgnoreMessageQueues_Configuration 
    

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

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

    Expand to view the stacktrace

     Expected testLogger.LogLevelSwitch.Level to be Error, but found Trace.
    Stack Trace:
       at FluentAssertions.Execution.XUnit2TestFramework.Throw(String message)
       at FluentAssertions.Execution.TestFrameworkProvider.Throw(String message)
       at FluentAssertions.Execution.DefaultAssertionStrategy.HandleFailure(String message)
       at FluentAssertions.Execution.AssertionScope.FailWith(Func`1 failReasonFunc)
       at FluentAssertions.Primitives.ObjectAssertions.Be(Object expected, String because, Object[] becauseArgs)
       at Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests.Should_Update_Logger_That_Is_ILogLevelSwitchable() in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1271/apm-agent-dotnet/test/Elastic.Apm.Tests/BackendCommTests/CentralConfig/CentralConfigFetcherTests.cs:line 78
    Standard Output:
        Elastic APM .NET Tests> 324> Xunit> [2021-06-23 23:53:39.690 +00:00][Info] - {LoggingTestBase} Starting test: Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests.Should_Update_Logger_That_Is_ILogLevelSwitchable...
        Elastic APM .NET Tests> 324> Xunit> [2021-06-23 23:54:39.939 +00:00][Info] - {LoggingTestBase} Finished test: Elastic.Apm.Tests.BackendCommTests.CentralConfig.CentralConfigFetcherTests.Should_Update_Logger_That_Is_ILogLevelSwitchable 
    

Steps errors 3

Expand to view the steps failures

Test & coverage
  • Took 2 min 28 sec . View more details on here
  • Description: .ci/windows/testnet461.bat
Archive the artifacts
  • Took 0 min 0 sec . View more details on here
  • Description: [2021-06-24T00:00:01.387Z] Archiving artifacts script returned exit code 1
Build
  • Took 1 min 35 sec . View more details on here
  • Description: .ci/windows/dotnet.bat

Log output

Expand to view the last 100 lines of log output

[2021-06-24T00:21:45.725Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Schema/ValidationEventArgs.cs. 
[2021-06-24T00:21:45.725Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Converters/StringEnumConverter.cs. 
[2021-06-24T00:21:45.800Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Converters/StringEnumConverter.cs. 
[2021-06-24T00:21:45.800Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Utilities/DynamicProxyMetaObject.cs. 
[2021-06-24T00:21:45.875Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Utilities/DynamicProxyMetaObject.cs. 
[2021-06-24T00:21:45.875Z] Starting copy source file Libraries/Newtonsoft.Json/Converters/StringEnumConverter.cs. 
[2021-06-24T00:21:45.955Z] Copied Libraries/Newtonsoft.Json/Converters/StringEnumConverter.cs. 
[2021-06-24T00:21:45.955Z] Starting copy source file Libraries/Newtonsoft.Json/Serialization/JsonPrimitiveContract.cs. 
[2021-06-24T00:21:46.024Z] Copied Libraries/Newtonsoft.Json/Serialization/JsonPrimitiveContract.cs. 
[2021-06-24T00:21:46.024Z] Starting copy source file Elastic.Apm/Config/AbstractConfigurationReader.cs. 
[2021-06-24T00:21:46.110Z] Copied Elastic.Apm/Config/AbstractConfigurationReader.cs. 
[2021-06-24T00:21:46.111Z] Starting copy source file Elastic.Apm/Filters/SpanStackTraceCapturingFilter.cs. 
[2021-06-24T00:21:46.190Z] Copied Elastic.Apm/Filters/SpanStackTraceCapturingFilter.cs. 
[2021-06-24T00:21:46.190Z] Starting copy source file Libraries/Newtonsoft.Json/Schema/JsonSchemaBuilder.cs. 
[2021-06-24T00:21:46.267Z] Copied Libraries/Newtonsoft.Json/Schema/JsonSchemaBuilder.cs. 
[2021-06-24T00:21:46.267Z] Starting copy source file Elastic.Apm/Helpers/ContractExtensions.cs. 
[2021-06-24T00:21:46.341Z] Copied Elastic.Apm/Helpers/ContractExtensions.cs. 
[2021-06-24T00:21:46.341Z] Starting copy source file Report/Serialization/MetricSetConverter.cs. 
[2021-06-24T00:21:46.416Z] Copied Report/Serialization/MetricSetConverter.cs. 
[2021-06-24T00:21:46.416Z] Starting copy source file Libraries/Newtonsoft.Json/Utilities/DynamicProxy.cs. 
[2021-06-24T00:21:46.489Z] Copied Libraries/Newtonsoft.Json/Utilities/DynamicProxy.cs. 
[2021-06-24T00:21:46.489Z] Starting copy source file Cloud/AzureCloudMetadataProvider.cs. 
[2021-06-24T00:21:46.561Z] Copied Cloud/AzureCloudMetadataProvider.cs. 
[2021-06-24T00:21:46.561Z] Starting copy source file Api/Context.cs. 
[2021-06-24T00:21:46.637Z] Copied Api/Context.cs. 
[2021-06-24T00:21:46.638Z] Starting copy source file Elastic.Apm/Libraries/Newtonsoft.Json/Serialization/DefaultContractResolver.cs. 
[2021-06-24T00:21:46.726Z] Copied Elastic.Apm/Libraries/Newtonsoft.Json/Serialization/DefaultContractResolver.cs. 
[2021-06-24T00:21:46.726Z] Starting copy source file Config/AbstractConfigurationReader.cs. 
[2021-06-24T00:21:46.811Z] Copied Config/AbstractConfigurationReader.cs. 
[2021-06-24T00:21:46.811Z] Starting copy source file Elastic.Apm/Logging/LogValuesFormatter.cs. 
[2021-06-24T00:21:46.886Z] Copied Elastic.Apm/Logging/LogValuesFormatter.cs. 
[2021-06-24T00:22:20.815Z] [Checks API] No suitable checks publisher found.
[2021-06-24T00:22:20.909Z] [INFO] getVaultSecret: Getting secrets
[2021-06-24T00:22:21.141Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID
[2021-06-24T00:22:21.764Z] Running in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1271/apm-agent-dotnet
[2021-06-24T00:22:21.783Z] [INFO] Codecov: Getting branch ref...
[2021-06-24T00:22:21.858Z] Masking supported pattern matches of $GITHUB_TOKEN
[2021-06-24T00:22:22.298Z] [INFO] Codecov: Sending data...
[2021-06-24T00:22:22.693Z] + echo curl -sSLo codecov.sh https://codecov.io/bash
[2021-06-24T00:22:22.694Z] curl -sSLo codecov.sh https://codecov.io/bash
[2021-06-24T00:22:23.010Z] + echo bash codecov.sh
[2021-06-24T00:22:23.010Z] bash codecov.sh
[2021-06-24T00:22:23.111Z] Archiving artifacts
[2021-06-24T00:22:23.211Z] java.lang.InterruptedException: no matches found within 10000
[2021-06-24T00:22:23.211Z] 	at hudson.FilePath$ValidateAntFileMask.hasMatch(FilePath.java:3069)
[2021-06-24T00:22:23.211Z] 	at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2978)
[2021-06-24T00:22:23.211Z] 	at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2929)
[2021-06-24T00:22:23.211Z] 	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3317)
[2021-06-24T00:22:23.211Z] Also:   hudson.remoting.Channel$CallSiteStackTrace: Remote call to JNLP4-connect connection from apm-ci-immutable-ubuntu-1804-1624491206901416871.c.elastic-ci-prod.internal/10.224.0.143:45152
[2021-06-24T00:22:23.211Z] 		at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1800)
[2021-06-24T00:22:23.211Z] 		at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:356)
[2021-06-24T00:22:23.211Z] 		at hudson.remoting.Channel.call(Channel.java:1001)
[2021-06-24T00:22:23.211Z] 		at hudson.FilePath.act(FilePath.java:1159)
[2021-06-24T00:22:23.211Z] 		at hudson.FilePath.act(FilePath.java:1148)
[2021-06-24T00:22:23.211Z] 		at hudson.FilePath.validateAntFileMask(FilePath.java:2927)
[2021-06-24T00:22:23.211Z] 		at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:270)
[2021-06-24T00:22:23.211Z] 		at org.jenkinsci.plugins.workflow.steps.CoreStep$Execution.run(CoreStep.java:99)
[2021-06-24T00:22:23.211Z] 		at org.jenkinsci.plugins.workflow.steps.CoreStep$Execution.run(CoreStep.java:69)
[2021-06-24T00:22:23.211Z] 		at org.jenkinsci.plugins.workflow.steps.SynchronousNonBlockingStepExecution.lambda$start$0(SynchronousNonBlockingStepExecution.java:47)
[2021-06-24T00:22:23.211Z] 		at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[2021-06-24T00:22:23.211Z] 		at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[2021-06-24T00:22:23.211Z] 		at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[2021-06-24T00:22:23.211Z] 		at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[2021-06-24T00:22:23.211Z] Caused: hudson.FilePath$TunneledInterruptedException
[2021-06-24T00:22:23.211Z] 	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3319)
[2021-06-24T00:22:23.211Z] 	at hudson.remoting.UserRequest.perform(UserRequest.java:211)
[2021-06-24T00:22:23.211Z] 	at hudson.remoting.UserRequest.perform(UserRequest.java:54)
[2021-06-24T00:22:23.211Z] 	at hudson.remoting.Request$2.run(Request.java:375)
[2021-06-24T00:22:23.211Z] 	at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:73)
[2021-06-24T00:22:23.211Z] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[2021-06-24T00:22:23.212Z] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[2021-06-24T00:22:23.212Z] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[2021-06-24T00:22:23.212Z] 	at hudson.remoting.Engine$1.lambda$newThread$0(Engine.java:118)
[2021-06-24T00:22:23.212Z] Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
[2021-06-24T00:22:23.212Z] 	at hudson.FilePath.act(FilePath.java:1161)
[2021-06-24T00:22:23.212Z] 	at hudson.FilePath.act(FilePath.java:1148)
[2021-06-24T00:22:23.212Z] 	at hudson.FilePath.validateAntFileMask(FilePath.java:2927)
[2021-06-24T00:22:23.212Z] 	at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:270)
[2021-06-24T00:22:23.212Z] 	at org.jenkinsci.plugins.workflow.steps.CoreStep$Execution.run(CoreStep.java:99)
[2021-06-24T00:22:23.212Z] 	at org.jenkinsci.plugins.workflow.steps.CoreStep$Execution.run(CoreStep.java:69)
[2021-06-24T00:22:23.212Z] 	at org.jenkinsci.plugins.workflow.steps.SynchronousNonBlockingStepExecution.lambda$start$0(SynchronousNonBlockingStepExecution.java:47)
[2021-06-24T00:22:23.212Z] 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[2021-06-24T00:22:23.212Z] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[2021-06-24T00:22:23.212Z] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[2021-06-24T00:22:23.212Z] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[2021-06-24T00:22:23.212Z] 	at java.lang.Thread.run(Thread.java:748)
[2021-06-24T00:22:23.212Z] No artifacts found that match the file pattern "/var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1271/**/MSBuild_*.failure.txt". Configuration error?
[2021-06-24T00:22:23.385Z] Stage "Release to feedz.io" skipped due to earlier failure(s)
[2021-06-24T00:22:23.425Z] Stage "Release" skipped due to earlier failure(s)
[2021-06-24T00:22:23.442Z] Stage "Release" skipped due to earlier failure(s)
[2021-06-24T00:22:23.483Z] Stage "Release" skipped due to earlier failure(s)
[2021-06-24T00:22:23.546Z] Stage "AfterRelease" skipped due to earlier failure(s)
[2021-06-24T00:22:23.563Z] Stage "AfterRelease" skipped due to earlier failure(s)
[2021-06-24T00:22:23.785Z] Running on Jenkins in /var/lib/jenkins/workspace/net_apm-agent-dotnet-mbp_PR-1271
[2021-06-24T00:22:23.837Z] [INFO] getVaultSecret: Getting secrets
[2021-06-24T00:22:23.879Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID
[2021-06-24T00:22:24.554Z] + chmod 755 generate-build-data.sh
[2021-06-24T00:22:24.554Z] + ./generate-build-data.sh https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1271/ https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1271/runs/51 FAILURE 2991060
[2021-06-24T00:22:24.554Z] INFO: curl https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1271/runs/51/steps/?limit=10000 -o steps-info.json
[2021-06-24T00:22:25.256Z] INFO: curl https://apm-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/apm-agent-dotnet/apm-agent-dotnet-mbp/PR-1271/runs/51/tests/?status=FAILED -o tests-errors.json

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.

Agent breakdown metrics (AKA Breakdown Graphs)
5 participants