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

feat(pdk) tracing pdk and core instrumentation #8724

Merged
merged 5 commits into from
May 25, 2022
Merged

Conversation

mayocream
Copy link
Contributor

@mayocream mayocream commented Apr 26, 2022

Summary

Feature request from #7321

Main tasks:

  • 1. Tracer PDK
    • pdk/tracing new tracing APIs that generally follow the OpenTemetry API spec.
    • pdk/tracing tracing storage with ngx.ctx.KONG_SPANS and store Active Span in ngx.ctx.<namespace>_active_span.
    • t/01-pdk/15-tracing span context tests.
    • spec/01-unit/26-tracer_spec PDK spec test, like input error assertion and checking basic tracer usages.
    • spec/02-integration/14-tracing integration tests, testing with a custom trace exporter plugin.
    • runloop/handler release related tables to the table pools, doing cleanup works.
    • propagation moved tracing_headers module (of Zipkin) to the core, to be a common module for any exporters, e.g. coming OTLP exporter.
  • 2. Build-in instrumentations
    • tracing/instrumentation wraps the tracer and adds hooks/hack.
    • Router / DB Query
    • Incoming HTTP Request
    • Balancer
    • Plugin iterator
    • DNS Query
  • 3. Misc
    • Configuration section in kong.conf.default
    • Changelog.md
    • LDoc comments

FT-2587

@mayocream mayocream force-pushed the feat/tracer-pdk branch 7 times, most recently from 56e866e to df6019a Compare April 27, 2022 06:00
@mayocream mayocream added this to the 3.0 milestone Apr 28, 2022
@mayocream mayocream marked this pull request as ready for review April 28, 2022 22:05
@mayocream mayocream requested a review from a team as a code owner April 28, 2022 22:05
@mayocream mayocream force-pushed the feat/tracer-pdk branch 2 times, most recently from 452f937 to 1142d36 Compare April 29, 2022 04:58
@mayocream mayocream requested review from fffonion and kikito May 2, 2022 00:00
kong/conf_loader/init.lua Outdated Show resolved Hide resolved
@mayocream mayocream force-pushed the feat/tracer-pdk branch 5 times, most recently from bfa5e60 to e827c3a Compare May 24, 2022 08:15
kong/globalpatches.lua Outdated Show resolved Hide resolved
@mayocream mayocream changed the title feat(pdk) tracing pdk and core instrumentation perf(pdk) tracing pdk and core instrumentation May 24, 2022
@github-actions github-actions bot added the chore Not part of the core functionality of kong, but still needed label May 24, 2022
@github-actions github-actions bot removed the chore Not part of the core functionality of kong, but still needed label May 24, 2022
@mayocream mayocream changed the title perf(pdk) tracing pdk and core instrumentation feat(pdk) tracing pdk and core instrumentation May 25, 2022
@mayocream
Copy link
Contributor Author

🚀 Performance test result

Test Suite: 01-rps 02-flamegraph (baseline,single_route,simple,admin_api)

["Imgur Images"]

Click to expand
Please see Github Actions artifacts for flamegraphs.

  ### Result for upstream directly (run 1):
Running 30s test @ http://10.103.96.3:8088/test
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   563.69us    1.25ms  12.12ms   87.36%
    Req/Sec   167.20k    12.26k  216.28k    65.96%
  24968388 requests in 30.10s, 3.26GB read
Requests/sec: 829535.52
Transfer/sec:    110.75MB
### Result for upstream directly (run 2):
Running 30s test @ http://10.103.96.3:8088/test
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   565.06us    1.25ms  16.03ms   87.33%
    Req/Sec   155.02k     7.79k  196.22k    72.29%
  23149586 requests in 30.10s, 3.02GB read
Requests/sec: 769108.07
Transfer/sec:    102.69MB
### Result for upstream directly (run 3):
Running 30s test @ http://10.103.96.3:8088/test
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   571.06us    1.26ms  12.16ms   87.29%
    Req/Sec   154.86k     7.97k  196.48k    70.67%
  23115014 requests in 30.04s, 3.01GB read
Requests/sec: 769599.86
Transfer/sec:    102.75MB
### Combined result for upstream directly:
RPS     Avg: 789414.48
Latency Avg: nanms    Max: nanms
  
### Test Suite: git:ce/perf/tracing-pdk #simple #no_plugins #single_route
### Result for Kong git:ce/perf/tracing-pdk (run 1):
Running 30s test @ http://10.103.96.1:8000/s1-r1
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.48ms    2.84ms  62.41ms   91.21%
    Req/Sec    29.55k     7.61k   54.83k    61.27%
  4410692 requests in 30.08s, 0.92GB read
Requests/sec: 146628.67
Transfer/sec:     31.46MB
### Result for Kong git:ce/perf/tracing-pdk (run 2):
Running 30s test @ http://10.103.96.1:8000/s1-r1
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.49ms    2.86ms  57.43ms   90.75%
    Req/Sec    29.86k     7.88k   53.33k    58.03%
  4460590 requests in 30.10s, 0.93GB read
Requests/sec: 148196.50
Transfer/sec:     31.79MB
### Result for Kong git:ce/perf/tracing-pdk (run 3):
Running 30s test @ http://10.103.96.1:8000/s1-r1
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.51ms    3.03ms  64.02ms   91.17%
    Req/Sec    30.01k     7.90k   55.89k    57.47%
  4478793 requests in 30.05s, 0.94GB read
Requests/sec: 149058.02
Transfer/sec:     31.98MB
### Combined result for Kong git:ce/perf/tracing-pdk:
RPS     Avg: 147961.06
Latency Avg: 1.49ms    Max: 64.02ms
  
### Test Suite: git:ce/perf/tracing-pdk #simple #no_plugins 10 services each has 10 routes
### Result for Kong git:ce/perf/tracing-pdk (run 1):
Running 30s test @ http://10.103.96.1:8000/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.46ms    2.86ms  59.05ms   91.50%
    Req/Sec    27.92k     7.04k   43.15k    57.46%
  4172950 requests in 30.07s, 0.87GB read
Requests/sec: 138796.93
Transfer/sec:     29.78MB
### Result for Kong git:ce/perf/tracing-pdk (run 2):
Running 30s test @ http://10.103.96.1:8000/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.50ms    2.95ms  57.87ms   91.55%
    Req/Sec    27.83k     7.23k   48.68k    57.92%
  4159429 requests in 30.07s, 0.87GB read
Requests/sec: 138342.74
Transfer/sec:     29.68MB
### Result for Kong git:ce/perf/tracing-pdk (run 3):
Running 30s test @ http://10.103.96.1:8000/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.48ms    3.04ms  60.34ms   91.89%
    Req/Sec    28.03k     7.01k   47.60k    57.99%
  4189375 requests in 30.07s, 0.88GB read
Requests/sec: 139315.46
Transfer/sec:     29.89MB
### Combined result for Kong git:ce/perf/tracing-pdk:
RPS     Avg: 138818.38
Latency Avg: 1.48ms    Max: 60.34ms
  
### Test Suite: git:ce/perf/tracing-pdk #simple #key-auth 10 services each has 10 routes with key-auth, 100 consumers
### Result for Kong git:ce/perf/tracing-pdk (run 1):
Running 30s test @ http://10.103.96.1:8000/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.46ms    2.66ms  66.73ms   92.70%
    Req/Sec    24.18k     5.52k   40.17k    59.75%
  3616203 requests in 30.10s, 775.79MB read
Requests/sec: 120142.76
Transfer/sec:     25.77MB
### Result for Kong git:ce/perf/tracing-pdk (run 2):
Running 30s test @ http://10.103.96.1:8000/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.44ms    2.58ms  59.28ms   92.42%
    Req/Sec    24.39k     5.55k   43.46k    60.19%
  3645668 requests in 30.06s, 782.11MB read
Requests/sec: 121291.22
Transfer/sec:     26.02MB
### Result for Kong git:ce/perf/tracing-pdk (run 3):
Running 30s test @ http://10.103.96.1:8000/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.43ms    2.67ms  60.80ms   92.86%
    Req/Sec    24.33k     5.56k   43.21k    60.01%
  3637993 requests in 30.10s, 780.46MB read
Requests/sec: 120867.03
Transfer/sec:     25.93MB
### Combined result for Kong git:ce/perf/tracing-pdk:
RPS     Avg: 120767.00
Latency Avg: 1.44ms    Max: 66.73ms
  
### Test Suite: git:ce/release/2.8.x #simple #no_plugins #single_route
### Result for Kong git:ce/release/2.8.x (run 1):
Running 30s test @ http://10.103.96.1:8000/s1-r1
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.50ms    2.91ms  48.60ms   90.94%
    Req/Sec    29.32k     7.73k   49.42k    58.13%
  4376430 requests in 30.03s, 0.92GB read
Requests/sec: 145726.97
Transfer/sec:     31.26MB
### Result for Kong git:ce/release/2.8.x (run 2):
Running 30s test @ http://10.103.96.1:8000/s1-r1
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.55ms    3.28ms  97.21ms   91.82%
    Req/Sec    29.50k     7.69k   52.67k    57.80%
  4403967 requests in 30.04s, 0.92GB read
Requests/sec: 146590.73
Transfer/sec:     31.45MB
### Result for Kong git:ce/release/2.8.x (run 3):
Running 30s test @ http://10.103.96.1:8000/s1-r1
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.48ms    2.83ms  55.38ms   90.91%
    Req/Sec    29.43k     7.67k   62.13k    59.33%
  4392600 requests in 30.04s, 0.92GB read
Requests/sec: 146203.10
Transfer/sec:     31.37MB
### Combined result for Kong git:ce/release/2.8.x:
RPS     Avg: 146173.60
Latency Avg: 1.51ms    Max: 97.21ms
  
### Test Suite: git:ce/release/2.8.x #simple #no_plugins 10 services each has 10 routes
### Result for Kong git:ce/release/2.8.x (run 1):
Running 30s test @ http://10.103.96.1:8000/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.44ms    2.70ms  52.03ms   91.11%
    Req/Sec    27.99k     7.11k   45.05k    58.08%
  4186063 requests in 30.10s, 0.88GB read
Requests/sec: 139075.68
Transfer/sec:     29.84MB
### Result for Kong git:ce/release/2.8.x (run 2):
Running 30s test @ http://10.103.96.1:8000/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.52ms    3.03ms  65.38ms   91.65%
    Req/Sec    27.78k     7.11k   49.37k    58.19%
  4151797 requests in 30.06s, 0.87GB read
Requests/sec: 138125.77
Transfer/sec:     29.63MB
### Result for Kong git:ce/release/2.8.x (run 3):
Running 30s test @ http://10.103.96.1:8000/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.48ms    2.95ms  87.85ms   91.50%
    Req/Sec    27.78k     7.16k   46.12k    58.52%
  4151686 requests in 30.07s, 0.87GB read
Requests/sec: 138062.12
Transfer/sec:     29.62MB
### Combined result for Kong git:ce/release/2.8.x:
RPS     Avg: 138421.19
Latency Avg: 1.48ms    Max: 87.85ms
  
### Test Suite: git:ce/release/2.8.x #simple #key-auth 10 services each has 10 routes with key-auth, 100 consumers
### Result for Kong git:ce/release/2.8.x (run 1):
Running 30s test @ http://10.103.96.1:8000/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.42ms    2.59ms  68.57ms   92.76%
    Req/Sec    24.16k     5.46k   37.46k    59.92%
  3610743 requests in 30.07s, 774.62MB read
Requests/sec: 120090.85
Transfer/sec:     25.76MB
### Result for Kong git:ce/release/2.8.x (run 2):
Running 30s test @ http://10.103.96.1:8000/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.42ms    2.66ms  61.24ms   92.65%
    Req/Sec    24.41k     5.50k   42.32k    61.65%
  3647950 requests in 30.06s, 782.60MB read
Requests/sec: 121359.24
Transfer/sec:     26.04MB
### Result for Kong git:ce/release/2.8.x (run 3):
Running 30s test @ http://10.103.96.1:8000/
  5 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.41ms    2.62ms  70.32ms   92.77%
    Req/Sec    24.36k     5.41k   43.76k    60.39%
  3641624 requests in 30.06s, 781.24MB read
Requests/sec: 121134.07
Transfer/sec:     25.99MB
### Combined result for Kong git:ce/release/2.8.x:
RPS     Avg: 120861.39
Latency Avg: 1.42ms    Max: 70.32ms
  

Kong error logs are also available in Github Actions artifacts.

Download Artifacts

kong/globalpatches.lua Outdated Show resolved Hide resolved
kong/globalpatches.lua Outdated Show resolved Hide resolved
mayocream and others added 3 commits May 25, 2022 17:37
Co-authored-by: Wangchong Zhou <fffonion@gmail.com>
Copy link
Contributor

@fffonion fffonion left a comment

Choose a reason for hiding this comment

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

🍔

@fffonion fffonion merged commit 4d29046 into master May 25, 2022
@fffonion fffonion deleted the feat/tracer-pdk branch May 25, 2022 10:36
-- @function kong.tracing.new_span
-- @phases rewrite, access, header_filter, response, body_filter, log, admin_api
-- @tparam table span
function self.set_active_span(span)
Copy link
Contributor

Choose a reason for hiding this comment

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

Would you add some comments to explain why we don't do this in start_span automatically?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

  1. We have to do the checking for the ctx.active_span to see if it exists, it could be expensive.
  2. At most of the time, the caller will not set the active span.

Comment on lines +311 to +315
if phase == "rewrite" then
span = instrumentation.plugin_rewrite(plugin)
elseif phase == "header_filter" then
span = instrumentation.plugin_header_filter(plugin)
end
Copy link
Contributor

Choose a reason for hiding this comment

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

Could we just do this?

instrumentation.plugin_phase(phase, plugin)

(exposing plugin_callback with name plugin_phase)

Copy link
Contributor Author

Choose a reason for hiding this comment

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

The function itself could be no-op, so I think use plugin_xxx format could be more easier.


-- Record DB query
function _M.db_query(connector)
local f = connector.query
Copy link
Contributor

Choose a reason for hiding this comment

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

Naming could be better.
And what if we save the original function, like

connector.query_origin = connector.query

So we can escape from tracing when needed?

For example:

http_export_request calls request_uri which is hooked here.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

I think there is no way back to the original function when we have patched :(

@JinhuW
Copy link

JinhuW commented Aug 15, 2022

Is there any documentation for us to learn how to use this feature?

@zffocussss
Copy link

is it compatible with elastic APM?

@zffocussss
Copy link

Is there any documentation for us to learn how to use this feature?

https://docs.konghq.com/hub/kong-inc/opentelemetry/

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.

7 participants