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

Add ECS log files to the intake log endpoint #9349

Merged
merged 14 commits into from
Oct 17, 2022

Conversation

lahsivjar
Copy link
Contributor

@lahsivjar lahsivjar commented Oct 12, 2022

Motivation/summary

Add ECS logging fields to intake API's log endpoint.

Checklist

How to test these changes

  1. Create a request body for the log event type:
{"metadata":{"process":{"pid":1234,"title":"/usr/lib/jvm/java-10-openjdk-amd64/bin/java","ppid":1,"argv":["-v"]},"system":{"architecture":"amd64","detected_hostname":"8ec7ceb99074","configured_hostname":"host1","platform":"Linux","container":{"id":"8ec7ceb990749e79b37f6dc6cd3628633618d6ce412553a552a0fa6b69419ad4"},"kubernetes":{"namespace":"default","pod":{"uid":"b17f231da0ad128dc6c6c0b2e82f6f303d3893e3","name":"instrumented-java-service"},"node":{"name":"node-name"}}},"service":{"name":"1234_service-12a3","version":"4.3.0","node":{"configured_name":"8ec7ceb990749e79b37f6dc6cd3628633618d6ce412553a552a0fa6b69419ad4"},"environment":"production","language":{"name":"Java","version":"10.0.2"},"agent":{"version":"1.10.0","name":"java","ephemeral_id":"e71be9ac-93b0-44b9-a997-5638f6ccfc36"},"framework":{"name":"spring","version":"5.0.0"},"runtime":{"name":"Java","version":"10.0.2"}},"labels":{"group":"experimental","ab_testing":true,"segment":5}}}
{"log": {"message": "test log message without timestamp"}}
{"log": {"message": "test log message with timestamp", "@timestamp": 1662616049000000}}
{"log": {"message": "test log message with string timestamp", "@timestamp": "2022-09-08T13:47:29.111-0800"}}
{"log": {"message": "test log message with faas", "@timestamp": 1662616049000000,"faas":{"coldstart":true,"execution":"6f7f0961f83442118a7af6fe80b88d56","id":"arn:aws:lambda:us-east-2:123456789012:function:custom-runtime"}}}
{"log": {"trace.id": "trace-id", "transaction.id": "txn-id", "log.level": "warn", "log.logger": "testLogger", "log.origin.file.name": "testFile", "log.origin.file.line": 10, "log.origin.function": "testFunc", "service.name": "testSvc", "service.version": "v1.0.0", "service.environment": "prod", "process.thread.name": "testThread", "dataset": "accesslog", "labels": {"str": "str", "int": 1, "float": 1.1, "bool": true}, "message": "test log message with faas and ecs fields", "@timestamp": 1662616049000000,"faas":{"coldstart":true,"execution":"6f7f0961f83442118a7af6fe80b88d56","id":"arn:aws:lambda:us-east-2:123456789012:function:custom-runtime"}}}
  1. Send a curl request with the above request body:
curl -i -H "Content-type: application/x-ndjson" -H "Authorization: Bearer {APM_SERVER_SECRET_TOKEN}" --data-binary @<request_body_path> {APM_SERVER_URL}:8200/intake/v2/events

Related issues

Closes #9100

@mergify
Copy link
Contributor

mergify bot commented Oct 12, 2022

This pull request does not have a backport label. Could you fix it @lahsivjar? 🙏
To fixup this pull request, you need to add the backport labels for the needed
branches, such as:

  • backport-7.x is the label to automatically backport to the 7.x branch.
  • backport-7./d is the label to automatically backport to the 7./d branch. /d is the digit

NOTE: backport-skip has been added to this pull request.

@mergify mergify bot added the backport-skip Skip notification from the automated backport with mergify label Oct 12, 2022
@apmmachine
Copy link
Contributor

apmmachine commented Oct 12, 2022

💚 Build Succeeded

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

Expand to view the summary

Build stats

  • Start Time: 2022-10-17T08:29:39.918+0000

  • Duration: 28 min 48 sec

Test stats 🧪

Test Results
Failed 0
Passed 154
Skipped 0
Total 154

🤖 GitHub comments

Expand to view the GitHub comments

To re-run your PR in the CI, just comment with:

  • /test : Re-trigger the build.

  • /package : Generate and publish the docker images.

  • /test windows : Build & tests on Windows.

  • run elasticsearch-ci/docs : Re-trigger the docs validation. (use unformatted text in the comment!)

@lahsivjar lahsivjar requested a review from a team October 12, 2022 06:47
Copy link
Member

@axw axw left a comment

Choose a reason for hiding this comment

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

Looks good, just left a couple of suggestions.

Handling maybe-flattened-maybe-not JSON will be interesting. I haven't looked into using it myself before, but json-iterator has an extension API which might be useful? https://pkg.go.dev/github.com/json-iterator/go#Extension

@lahsivjar
Copy link
Contributor Author

lahsivjar commented Oct 13, 2022

Handling maybe-flattened-maybe-not JSON will be interesting. I haven't looked into using it myself before, but json-iterator has an extension API which might be useful? https://pkg.go.dev/github.com/json-iterator/go#Extension

@axw Thanks for this. I was not aware of this and my searches also came up empty, it sounds way better than what I am doing right now which is introducing a map to decode the nested structure into and finally merging them with the flat decoded values via generated code. Something like this:

type ecsLogService struct {
	NestedStruct map[string]interface{} `json:"service" flattenSource:"true"`
	ServiceName nullable.String `json:"service.name" validate:"maxLength=1024"`
	ServiceVersion nullable.String `json:"service.version" validate:"maxLength=1024"`
	ServiceEnvironment nullable.String `json:"service.environment" validate:"maxLength=1024"`
	ServiceNodeName nullable.String `json:"service.node.name" validate:"maxLength=1024"`
}

Finally, the generator will scan the json tags and output a function that can be called to merge the nested decoded values into the flat values.

@lahsivjar lahsivjar requested a review from axw October 14, 2022 06:46
@apmmachine
Copy link
Contributor

apmmachine commented Oct 14, 2022

📚 Go benchmark report

Diff with the main branch

name                                                                                              old time/op    new time/op    delta
pkg:github.com/elastic/apm-server/internal/agentcfg goos:linux goarch:amd64
FetchAndAdd/FetchFromCache-12                                                                       46.2ns ± 0%    41.1ns ± 0%   -10.97%  (p=0.008 n=5+5)
FetchAndAdd/FetchAndAddToCache-12                                                                    108ns ± 2%      99ns ± 3%    -8.80%  (p=0.008 n=5+5)
pkg:github.com/elastic/apm-server/internal/beater/request goos:linux goarch:amd64
ContextReset/X-Real-IP_ipv4-12                                                                       605ns ±51%     912ns ±10%   +50.66%  (p=0.016 n=5+5)
ContextReset/X-Forwarded-For_ipv6-12                                                                 621ns ±52%     970ns ±13%   +56.11%  (p=0.008 n=5+5)
ContextResetContentEncoding/uncompressed-12                                                          166ns ± 1%     147ns ± 0%   -11.22%  (p=0.008 n=5+5)
ContextResetContentEncoding/gzip_sniff-12                                                           2.53µs ±58%    4.13µs ± 1%   +62.79%  (p=0.008 n=5+5)
ContextResetContentEncoding/deflate_sniff-12                                                        2.36µs ±64%    3.93µs ± 5%   +66.24%  (p=0.008 n=5+5)
pkg:github.com/elastic/apm-server/internal/model/modelindexer goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/internal/processor/stream goos:linux goarch:amd64
BackendProcessor/errors_rum.ndjson-12                                                               19.1µs ±46%    29.6µs ±20%   +55.15%  (p=0.032 n=5+5)
BackendProcessor/errors_transaction_id.ndjson-12                                                    51.4µs ±53%    68.4µs ±14%   +32.97%  (p=0.032 n=5+5)
BackendProcessor/heavy.ndjson-12                                                                    3.47ms ±18%    4.67ms ±17%   +34.50%  (p=0.016 n=5+5)
BackendProcessor/logs.ndjson-12                                                                     24.1µs ±46%    83.5µs ±24%  +245.93%  (p=0.008 n=5+5)
BackendProcessor/transactions_spans_rum_2.ndjson-12                                                 14.5µs ±50%    22.7µs ±21%   +56.95%  (p=0.016 n=5+5)
BackendProcessor/unknown-span-type.ndjson-12                                                        51.1µs ±28%    69.9µs ±35%   +36.75%  (p=0.032 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel2/logs.ndjson-12                          6.75µs ±37%   18.48µs ± 7%  +173.86%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel4/logs.ndjson-12                          4.48µs ±19%   12.25µs ±11%  +173.39%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel4/span-links.ndjson-12                    2.56µs ±15%    3.02µs ± 9%   +17.84%  (p=0.032 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel4/unknown-span-type.ndjson-12             12.9µs ± 8%    13.9µs ± 2%    +7.78%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel8/logs.ndjson-12                          2.37µs ± 3%    6.28µs ± 0%  +164.83%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel8/transactions_spans.ndjson-12            11.0µs ± 1%    11.4µs ± 1%    +3.05%  (p=0.016 n=4+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel8/transactions_spans_rum.ndjson-12        2.04µs ± 1%    2.08µs ± 1%    +1.64%  (p=0.016 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/heavy.ndjson-12                        494µs ± 2%     525µs ± 2%    +6.23%  (p=0.016 n=4+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/invalid-metadata.ndjson-12             490ns ± 1%     511ns ± 1%    +4.25%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/logs.ndjson-12                        1.96µs ± 7%    5.65µs ± 3%  +188.91%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/metricsets.ndjson-12                  4.39µs ± 1%    4.56µs ± 1%    +3.74%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/minimal-service.ndjson-12              956ns ± 1%    1009ns ± 3%    +5.63%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/minimal.ndjson-12                     1.98µs ± 3%    2.06µs ± 3%    +3.88%  (p=0.032 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/optional-timestamps.ndjson-12         1.45µs ± 2%    1.50µs ± 2%    +3.24%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/span-links.ndjson-12                  1.19µs ± 2%    1.22µs ± 1%    +2.39%  (p=0.016 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/transactions.ndjson-12                9.40µs ± 1%    9.55µs ± 1%    +1.61%  (p=0.032 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/transactions_spans.ndjson-12          9.30µs ± 2%    9.59µs ± 2%    +3.06%  (p=0.016 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/transactions_spans_rum.ndjson-12      1.60µs ± 2%    1.63µs ± 1%    +2.18%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/transactions_spans_rum_2.ndjson-12    1.52µs ± 1%    1.56µs ± 1%    +2.54%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/unknown-span-type.ndjson-12           6.12µs ± 1%    6.34µs ± 3%    +3.57%  (p=0.008 n=5+5)
ReadBatch/errors_transaction_id.ndjson-12                                                           65.1µs ±36%    84.1µs ±13%   +29.23%  (p=0.032 n=5+5)
ReadBatch/logs.ndjson-12                                                                            27.6µs ±27%    73.4µs ±19%  +165.95%  (p=0.008 n=5+5)
ReadBatch/ratelimit.ndjson-12                                                                       42.5µs ±21%    53.9µs ±25%   +26.94%  (p=0.032 n=5+5)
ReadBatch/spans.ndjson-12                                                                           91.3µs ±16%   135.0µs ±25%   +47.89%  (p=0.008 n=5+5)
pkg:github.com/elastic/apm-server/internal/publish goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/x-pack/apm-server/aggregation/spanmetrics goos:linux goarch:amd64
AggregateSpan-12                                                                                    1.28µs ±22%    1.00µs ± 7%   -21.32%  (p=0.008 n=5+5)
pkg:github.com/elastic/apm-server/x-pack/apm-server/aggregation/txmetrics goos:linux goarch:amd64
AggregateTransaction-12                                                                             83.4ns ± 1%    84.8ns ± 1%    +1.62%  (p=0.008 n=5+5)
pkg:github.com/elastic/apm-server/x-pack/apm-server/sampling goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/x-pack/apm-server/sampling/eventstorage goos:linux goarch:amd64
WriteTransaction/json_codec-12                                                                      11.8µs ±42%     4.2µs ± 4%   -64.45%  (p=0.008 n=5+5)
WriteTransaction/json_codec_big_tx-12                                                               14.3µs ±33%     4.9µs ± 3%   -65.39%  (p=0.008 n=5+5)
ReadEvents/json_codec/0_events-12                                                                    351ns ± 3%     308ns ± 4%   -12.41%  (p=0.008 n=5+5)
ReadEvents/json_codec/399_events-12                                                                 2.75ms ± 2%    2.94ms ± 4%    +6.99%  (p=0.008 n=5+5)
ReadEvents/json_codec_big_tx/100_events-12                                                           937µs ± 3%     971µs ± 2%    +3.63%  (p=0.008 n=5+5)
ReadEvents/json_codec_big_tx/399_events-12                                                          3.41ms ± 3%    3.63ms ± 5%    +6.32%  (p=0.008 n=5+5)
ReadEvents/nop_codec/0_events-12                                                                     348ns ± 9%     310ns ± 6%   -11.12%  (p=0.008 n=5+5)
IsTraceSampled/sampled-12                                                                           75.2ns ± 2%    68.1ns ± 3%    -9.42%  (p=0.008 n=5+5)
IsTraceSampled/unsampled-12                                                                         78.0ns ± 2%    70.7ns ± 1%    -9.33%  (p=0.008 n=5+5)
IsTraceSampled/unknown-12                                                                            412ns ± 3%     374ns ± 1%    -9.31%  (p=0.008 n=5+5)

name                                                                                              old alloc/op   new alloc/op   delta
pkg:github.com/elastic/apm-server/internal/agentcfg goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/internal/beater/request goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/internal/model/modelindexer goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/internal/processor/stream goos:linux goarch:amd64
BackendProcessor/errors_transaction_id.ndjson-12                                                    18.9kB ± 1%    19.2kB ± 1%    +1.56%  (p=0.032 n=5+5)
BackendProcessor/heavy.ndjson-12                                                                     838kB ± 1%     862kB ± 1%    +2.81%  (p=0.008 n=5+5)
BackendProcessor/invalid-json-event.ndjson-12                                                       4.11kB ± 1%    4.18kB ± 2%    +1.86%  (p=0.032 n=5+5)
BackendProcessor/invalid-json-metadata.ndjson-12                                                    5.18kB ± 1%    5.28kB ± 1%    +1.90%  (p=0.032 n=5+5)
BackendProcessor/logs.ndjson-12                                                                     8.52kB ± 1%   19.56kB ± 1%  +129.62%  (p=0.008 n=5+5)
BackendProcessor/minimal-service.ndjson-12                                                          3.62kB ± 1%    3.69kB ± 2%    +2.03%  (p=0.032 n=5+5)
BackendProcessor/minimal.ndjson-12                                                                  5.56kB ± 1%    5.71kB ± 1%    +2.75%  (p=0.008 n=5+5)
BackendProcessor/otel-bridge.ndjson-12                                                              10.9kB ± 1%    11.1kB ± 2%    +1.94%  (p=0.024 n=5+5)
BackendProcessor/ratelimit.ndjson-12                                                                11.2kB ± 1%    11.7kB ± 4%    +4.80%  (p=0.008 n=5+5)
BackendProcessor/transactions_spans_rum_2.ndjson-12                                                 5.47kB ± 1%    5.56kB ± 1%    +1.73%  (p=0.032 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel2/heavy.ndjson-12                          847kB ± 1%     868kB ± 1%    +2.50%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel2/logs.ndjson-12                          9.32kB ± 1%   20.49kB ± 2%  +119.92%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel2/minimal.ndjson-12                       6.37kB ± 2%    6.59kB ± 2%    +3.40%  (p=0.032 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel4/heavy.ndjson-12                          853kB ± 1%     867kB ± 1%    +1.58%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel4/logs.ndjson-12                          9.23kB ± 2%   20.63kB ± 1%  +123.50%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel4/ratelimit.ndjson-12                     12.2kB ± 2%    12.3kB ± 0%    +1.39%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel8/heavy.ndjson-12                          849kB ± 1%     867kB ± 0%    +2.15%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel8/invalid-event.ndjson-12                 8.29kB ± 3%    8.40kB ± 1%    +1.40%  (p=0.032 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel8/logs.ndjson-12                          9.16kB ± 1%   20.30kB ± 1%  +121.63%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel8/minimal.ndjson-12                       6.22kB ± 2%    6.37kB ± 1%    +2.52%  (p=0.032 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/errors.ndjson-12                      22.3kB ± 1%    22.6kB ± 1%    +1.59%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/heavy.ndjson-12                        841kB ± 1%     862kB ± 2%    +2.47%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/logs.ndjson-12                        8.97kB ± 2%   20.09kB ± 1%  +124.08%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/ratelimit.ndjson-12                   11.5kB ± 2%    11.9kB ± 3%    +3.50%  (p=0.032 n=5+5)
BackendProcessorAsync/heavy.ndjson-12                                                                967kB ± 1%     987kB ± 1%    +2.03%  (p=0.016 n=5+5)
ReadBatch/errors.ndjson-12                                                                          20.6kB ± 0%    20.8kB ± 0%    +0.86%  (p=0.008 n=5+5)
ReadBatch/errors_2.ndjson-12                                                                        22.6kB ± 0%    22.7kB ± 0%    +0.55%  (p=0.008 n=5+5)
ReadBatch/errors_rum.ndjson-12                                                                      6.83kB ± 0%    6.86kB ± 0%    +0.48%  (p=0.008 n=5+5)
ReadBatch/errors_transaction_id.ndjson-12                                                           18.0kB ± 0%    18.0kB ± 0%    +0.23%  (p=0.008 n=5+5)
ReadBatch/heavy.ndjson-12                                                                            824kB ± 0%     838kB ± 0%    +1.74%  (p=0.008 n=5+5)
ReadBatch/logs.ndjson-12                                                                            7.55kB ± 0%   18.34kB ± 0%  +142.91%  (p=0.008 n=5+5)
ReadBatch/metadata-null-values.ndjson-12                                                            2.38kB ± 0%    2.42kB ± 0%    +1.31%  (p=0.008 n=5+5)
ReadBatch/minimal-service.ndjson-12                                                                 2.76kB ± 0%    2.79kB ± 0%    +1.20%  (p=0.008 n=5+5)
ReadBatch/minimal.ndjson-12                                                                         4.68kB ± 0%    4.77kB ± 0%    +2.08%  (p=0.008 n=5+5)
ReadBatch/ratelimit.ndjson-12                                                                       10.3kB ± 0%    10.5kB ± 0%    +1.60%  (p=0.008 n=5+5)
ReadBatch/transactions_spans_rum.ndjson-12                                                          4.71kB ± 0%    4.70kB ± 0%    -0.09%  (p=0.016 n=5+4)
pkg:github.com/elastic/apm-server/internal/publish goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/x-pack/apm-server/aggregation/spanmetrics goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/x-pack/apm-server/aggregation/txmetrics goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/x-pack/apm-server/sampling goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/x-pack/apm-server/sampling/eventstorage goos:linux goarch:amd64
WriteTransaction/json_codec-12                                                                      3.00kB ± 0%    3.00kB ± 0%    -0.03%  (p=0.016 n=5+4)
WriteTransaction/json_codec_big_tx-12                                                               3.90kB ± 0%    3.90kB ± 0%    -0.05%  (p=0.016 n=5+4)
ReadEvents/json_codec/199_events-12                                                                 1.10MB ± 0%    1.10MB ± 0%    +0.10%  (p=0.016 n=4+5)
ReadEvents/json_codec/399_events-12                                                                 1.64MB ± 0%    1.64MB ± 0%    +0.16%  (p=0.008 n=5+5)
ReadEvents/json_codec/1000_events-12                                                                3.45MB ± 1%    3.48MB ± 0%    +0.94%  (p=0.016 n=5+4)
ReadEvents/json_codec_big_tx/399_events-12                                                          2.22MB ± 0%    2.22MB ± 0%    +0.19%  (p=0.032 n=5+5)
ReadEvents/nop_codec_big_tx/100_events-12                                                            250kB ± 0%     250kB ± 0%    +0.09%  (p=0.008 n=5+5)
ReadEvents/nop_codec_big_tx/199_events-12                                                            470kB ± 0%     470kB ± 0%    +0.18%  (p=0.032 n=4+5)

name                                                                                              old allocs/op  new allocs/op  delta
pkg:github.com/elastic/apm-server/internal/agentcfg goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/internal/beater/request goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/internal/model/modelindexer goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/internal/processor/stream goos:linux goarch:amd64
BackendProcessor/heavy.ndjson-12                                                                     22.3k ± 0%     22.3k ± 0%    +0.01%  (p=0.008 n=5+5)
BackendProcessor/logs.ndjson-12                                                                       65.0 ± 0%     331.0 ± 0%  +409.23%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel2/logs.ndjson-12                            65.0 ± 0%     331.0 ± 0%  +409.23%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel4/logs.ndjson-12                            65.0 ± 0%     331.0 ± 0%  +409.23%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel8/logs.ndjson-12                            65.0 ± 0%     331.0 ± 0%  +409.23%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/logs.ndjson-12                          65.0 ± 0%     331.0 ± 0%  +409.23%  (p=0.008 n=5+5)
ReadBatch/logs.ndjson-12                                                                              62.0 ± 0%     328.0 ± 0%  +429.03%  (p=0.008 n=5+5)
pkg:github.com/elastic/apm-server/internal/publish goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/x-pack/apm-server/aggregation/spanmetrics goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/x-pack/apm-server/aggregation/txmetrics goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/x-pack/apm-server/sampling goos:linux goarch:amd64
pkg:github.com/elastic/apm-server/x-pack/apm-server/sampling/eventstorage goos:linux goarch:amd64

name                                                                                              old speed      new speed      delta
pkg:github.com/elastic/apm-server/internal/processor/stream goos:linux goarch:amd64
BackendProcessor/errors_rum.ndjson-12                                                              113MB/s ±47%    65MB/s ±18%   -42.76%  (p=0.032 n=5+5)
BackendProcessor/errors_transaction_id.ndjson-12                                                  84.1MB/s ±86%  56.4MB/s ±15%   -32.91%  (p=0.032 n=5+5)
BackendProcessor/heavy.ndjson-12                                                                   116MB/s ±16%    87MB/s ±18%   -25.28%  (p=0.016 n=5+5)
BackendProcessor/transactions_spans_rum_2.ndjson-12                                               86.6MB/s ±78%  50.2MB/s ±24%   -42.05%  (p=0.016 n=5+5)
BackendProcessor/unknown-span-type.ndjson-12                                                      66.8MB/s ±34%  48.7MB/s ±28%   -27.11%  (p=0.032 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel4/span-links.ndjson-12                   268MB/s ±13%   227MB/s ± 9%   -15.34%  (p=0.032 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel4/unknown-span-type.ndjson-12            257MB/s ± 8%   238MB/s ± 2%    -7.36%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel8/transactions_spans.ndjson-12           526MB/s ± 1%   511MB/s ± 1%    -2.96%  (p=0.016 n=4+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel8/transactions_spans_rum.ndjson-12       565MB/s ± 1%   556MB/s ± 1%    -1.62%  (p=0.016 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/heavy.ndjson-12                      807MB/s ± 2%   760MB/s ± 2%    -5.86%  (p=0.016 n=4+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/invalid-metadata.ndjson-12           910MB/s ± 1%   873MB/s ± 1%    -4.08%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/logs.ndjson-12                       679MB/s ± 7%   617MB/s ± 3%    -9.06%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/metricsets.ndjson-12                 579MB/s ± 1%   559MB/s ± 1%    -3.61%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/minimal-service.ndjson-12            445MB/s ± 1%   421MB/s ± 2%    -5.30%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/minimal.ndjson-12                    520MB/s ± 3%   501MB/s ± 3%    -3.75%  (p=0.032 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/optional-timestamps.ndjson-12        706MB/s ± 2%   684MB/s ± 2%    -3.13%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/span-links.ndjson-12                 574MB/s ± 2%   560MB/s ± 1%    -2.36%  (p=0.016 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/transactions.ndjson-12               601MB/s ± 1%   591MB/s ± 1%    -1.58%  (p=0.032 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/transactions_spans.ndjson-12         626MB/s ± 2%   607MB/s ± 2%    -2.98%  (p=0.016 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/transactions_spans_rum.ndjson-12     724MB/s ± 2%   709MB/s ± 1%    -2.15%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/transactions_spans_rum_2.ndjson-12   735MB/s ± 1%   717MB/s ± 1%    -2.49%  (p=0.008 n=5+5)
BackendProcessorParallel/BenchmarkBackendProcessorParallel200/unknown-span-type.ndjson-12          540MB/s ± 1%   521MB/s ± 3%    -3.43%  (p=0.008 n=5+5)
ReadBatch/errors_transaction_id.ndjson-12                                                         62.0MB/s ±48%  45.9MB/s ±14%   -25.95%  (p=0.032 n=5+5)
ReadBatch/ratelimit.ndjson-12                                                                      101MB/s ±19%    79MB/s ±21%   -20.98%  (p=0.032 n=5+5)
ReadBatch/spans.ndjson-12                                                                         88.8MB/s ±15%  60.9MB/s ±22%   -31.47%  (p=0.008 n=5+5)

report generated with https://pkg.go.dev/golang.org/x/perf/cmd/benchstat

@felixbarny
Copy link
Member

Another edge case that's worth discussing is how to deal with duplicate keys. As ECS loggers allow users to add arbitrary keys at the top level, the resulting JSON may contain duplicate keys, such as log.level appearing twice. Ideally, the JSON processing should not fail but just use the last value. But that's definitely something we can look at in a follow-up.

@SylvainJuge
Copy link
Member

When testing this PR with Java agent draft PR, I get a parsing error on the @timestamp field which seems to be parsed a uint64 field and not as an usual datetime field, is that intentional ?

It's quite easy to reproduce with the following payload:

{"metadata":{"process":{"pid":1234,"title":"/usr/lib/jvm/java-10-openjdk-amd64/bin/java","ppid":1,"argv":["-v"]},"system":{"architecture":"amd64","detected_hostname":"8ec7ceb99074","configured_hostname":"host1","platform":"Linux","container":{"id":"8ec7ceb990749e79b37f6dc6cd3628633618d6ce412553a552a0fa6b69419ad4"},"kubernetes":{"namespace":"default","pod":{"uid":"b17f231da0ad128dc6c6c0b2e82f6f303d3893e3","name":"instrumented-java-service"},"node":{"name":"node-name"}}},"service":{"name":"1234_service-12a3","version":"4.3.0","node":{"configured_name":"8ec7ceb990749e79b37f6dc6cd3628633618d6ce412553a552a0fa6b69419ad4"},"environment":"production","language":{"name":"Java","version":"10.0.2"},"agent":{"version":"1.10.0","name":"java","ephemeral_id":"e71be9ac-93b0-44b9-a997-5638f6ccfc36"},"framework":{"name":"spring","version":"5.0.0"},"runtime":{"name":"Java","version":"10.0.2"}},"labels":{"group":"experimental","ab_testing":true,"segment":5}}}
{"log": {"message": "test log message with timestamp", "@timestamp": "2022-10-14T14:11:54.312+0200"}}

@felixbarny
Copy link
Member

felixbarny commented Oct 14, 2022

Great point. Yeah, the @timestamp field should support being provided as an ISO date or as a number. Unless the server needs to process the timestamp in some way (like when aggregating metrics on top of logs), it would be reasonable to just forward the timestamp to Elasticsearch which can handle the timestamp in both number and ISO date string format. The default date format supported by ES is strict_date_optional_time||epoch_millis. See also https://www.elastic.co/guide/en/elasticsearch/reference/current/date.html.

Thanks for testing this @SylvainJuge 👏

@elastic elastic deleted a comment from sabrican3532 Oct 17, 2022
@lahsivjar
Copy link
Contributor Author

lahsivjar commented Oct 17, 2022

Thanks, @SylvainJuge, and @felixbarny for the proactive feedback and testing.

Currently, APM-Server only supports epoch_millis for timestamp. Since APM-Server batches data before sending I think sending timestamp string directly to Elasticsearch might not be suitable as it would lead to failures in the ES layer even though APM-Server accepted the request. I am thinking of supporting this at the APM-Server level, do you think supporting a stricter format of 2022-10-14T14:11:54.312+0200 OR strict_date_time || epoch_millis would be enough, or do we need to support the full strice_date_optional_time || epoch_millis?

UPDATE: I have added a PR #9376 to add support for string timestamp. For now, I have only added format 2022-10-14T14:11:54.312+0200 but if required I can add formats for strice_date_optional_time OR strict_date_time.

@felixbarny
Copy link
Member

Yes, I think strict_date_time || epoch_millis would be good enough.

@lahsivjar
Copy link
Contributor Author

@felixbarny Thanks for the clarification. Based on this doc, IIUC, strict_date_time accepts only the format yyyy-MM-dd'T'HH:mm:ss.SSSZ. Is this correct?

@felixbarny
Copy link
Member

Yes, that's correct.

@mergify
Copy link
Contributor

mergify bot commented Oct 17, 2022

This pull request is now in conflicts. Could you fix it @lahsivjar? 🙏
To fixup this pull request, you can check out it locally. See documentation: https://help.github.com/articles/checking-out-pull-requests-locally/

git fetch upstream
git checkout -b 9100_ecs_logs upstream/9100_ecs_logs
git merge upstream/main
git push upstream 9100_ecs_logs

Copy link
Member

@axw axw left a comment

Choose a reason for hiding this comment

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

LGTM! Just a couple of minor things.

],
"maxLength": 1024
},
"ecslogerrorfields": {
Copy link
Member

Choose a reason for hiding this comment

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

I wonder if we should just not produce JSON Schema for logs for now? IIRC that's what @felixbarny suggested earlier. Otherwise we should probably ensure the embedded structs don't affect the schema.

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 wonder if we should just not produce JSON Schema for logs for now?

How are the generated specs utilized? FWIW, I was planning on fixing the embedded struct handling in the schema generation code but if we don't have a use case for the schema or if it is not required for the logs then removing it sounds good to me.

Copy link
Member

@axw axw Oct 17, 2022

Choose a reason for hiding this comment

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

At least some of the agents use the schema for payload validation in tests. We used to use it in APM Server, before we generated the validation code. Let's drop it for now and come back to it if agents want to start validating logs payloads.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Thanks @axw, I have removed the JSON spec generation for now.

@lahsivjar lahsivjar enabled auto-merge (squash) October 17, 2022 08:33
@lahsivjar lahsivjar merged commit 347784d into elastic:main Oct 17, 2022
@lahsivjar lahsivjar deleted the 9100_ecs_logs branch October 17, 2022 09:35
@lahsivjar
Copy link
Contributor Author

@SylvainJuge Thanks for the earlier testing. Whenever you have time can you test again with the JAVA agent as all the required PRs are now merged.

@SylvainJuge
Copy link
Member

@SylvainJuge Thanks for the earlier testing. Whenever you have time can you test again with the JAVA agent as all the required PRs are now merged.

I just did a quick test and it seems that not all "string-based" timestamps formats are supported, see #9376 (comment) for an example.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
backport-skip Skip notification from the automated backport with mergify
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Add fields from ECS logging spec to log support in v2 intake API
5 participants