-
Notifications
You must be signed in to change notification settings - Fork 324
Fix Synapse passthru spans finishing before status code is available #10478
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
base: master
Are you sure you want to change the base?
Conversation
BenchmarksStartupParameters
See matching parameters
SummaryFound 0 performance improvements and 0 performance regressions! Performance is the same for 64 metrics, 7 unstable metrics. Startup time reports for petclinicgantt
title petclinic - global startup overhead: candidate=1.59.0-SNAPSHOT~3f18bf9da6, baseline=1.59.0-SNAPSHOT~02cc48359b
dateFormat X
axisFormat %s
section tracing
Agent [baseline] (1.062 s) : 0, 1062036
Total [baseline] (11.013 s) : 0, 11012504
Agent [candidate] (1.06 s) : 0, 1060365
Total [candidate] (10.946 s) : 0, 10945864
section appsec
Agent [baseline] (1.245 s) : 0, 1245099
Total [baseline] (11.104 s) : 0, 11103659
Agent [candidate] (1.257 s) : 0, 1256891
Total [candidate] (11.163 s) : 0, 11162567
section iast
Agent [baseline] (1.229 s) : 0, 1229393
Total [baseline] (11.164 s) : 0, 11163502
Agent [candidate] (1.231 s) : 0, 1230500
Total [candidate] (11.204 s) : 0, 11204364
section profiling
Agent [baseline] (1.203 s) : 0, 1203479
Total [baseline] (11.141 s) : 0, 11140725
Agent [candidate] (1.188 s) : 0, 1188250
Total [candidate] (11.018 s) : 0, 11017564
gantt
title petclinic - break down per module: candidate=1.59.0-SNAPSHOT~3f18bf9da6, baseline=1.59.0-SNAPSHOT~02cc48359b
dateFormat X
axisFormat %s
section tracing
crashtracking [baseline] (1.189 ms) : 0, 1189
crashtracking [candidate] (1.189 ms) : 0, 1189
BytebuddyAgent [baseline] (625.485 ms) : 0, 625485
BytebuddyAgent [candidate] (623.345 ms) : 0, 623345
AgentMeter [baseline] (28.687 ms) : 0, 28687
AgentMeter [candidate] (28.726 ms) : 0, 28726
GlobalTracer [baseline] (258.169 ms) : 0, 258169
GlobalTracer [candidate] (257.185 ms) : 0, 257185
AppSec [baseline] (32.95 ms) : 0, 32950
AppSec [candidate] (32.851 ms) : 0, 32851
Debugger [baseline] (61.076 ms) : 0, 61076
Debugger [candidate] (62.502 ms) : 0, 62502
Remote Config [baseline] (616.828 µs) : 0, 617
Remote Config [candidate] (610.096 µs) : 0, 610
Telemetry [baseline] (9.193 ms) : 0, 9193
Telemetry [candidate] (9.997 ms) : 0, 9997
Flare Poller [baseline] (9.219 ms) : 0, 9219
Flare Poller [candidate] (8.606 ms) : 0, 8606
section appsec
crashtracking [baseline] (1.198 ms) : 0, 1198
crashtracking [candidate] (1.211 ms) : 0, 1211
BytebuddyAgent [baseline] (660.4 ms) : 0, 660400
BytebuddyAgent [candidate] (667.407 ms) : 0, 667407
AgentMeter [baseline] (11.951 ms) : 0, 11951
AgentMeter [candidate] (12.088 ms) : 0, 12088
GlobalTracer [baseline] (260.133 ms) : 0, 260133
GlobalTracer [candidate] (262.549 ms) : 0, 262549
AppSec [baseline] (168.409 ms) : 0, 168409
AppSec [candidate] (170.275 ms) : 0, 170275
Debugger [baseline] (68.08 ms) : 0, 68080
Debugger [candidate] (67.635 ms) : 0, 67635
Remote Config [baseline] (670.453 µs) : 0, 670
Remote Config [candidate] (671.018 µs) : 0, 671
Telemetry [baseline] (9.338 ms) : 0, 9338
Telemetry [candidate] (9.312 ms) : 0, 9312
Flare Poller [baseline] (3.694 ms) : 0, 3694
Flare Poller [candidate] (3.658 ms) : 0, 3658
IAST [baseline] (25.564 ms) : 0, 25564
IAST [candidate] (26.316 ms) : 0, 26316
section iast
crashtracking [baseline] (1.187 ms) : 0, 1187
crashtracking [candidate] (1.186 ms) : 0, 1186
BytebuddyAgent [baseline] (791.703 ms) : 0, 791703
BytebuddyAgent [candidate] (792.632 ms) : 0, 792632
AgentMeter [baseline] (11.198 ms) : 0, 11198
AgentMeter [candidate] (11.222 ms) : 0, 11222
GlobalTracer [baseline] (248.881 ms) : 0, 248881
GlobalTracer [candidate] (248.897 ms) : 0, 248897
AppSec [baseline] (33.999 ms) : 0, 33999
AppSec [candidate] (34.961 ms) : 0, 34961
Debugger [baseline] (67.301 ms) : 0, 67301
Debugger [candidate] (66.587 ms) : 0, 66587
Remote Config [baseline] (550.584 µs) : 0, 551
Remote Config [candidate] (550.528 µs) : 0, 551
Telemetry [baseline] (8.596 ms) : 0, 8596
Telemetry [candidate] (8.59 ms) : 0, 8590
Flare Poller [baseline] (3.529 ms) : 0, 3529
Flare Poller [candidate] (3.481 ms) : 0, 3481
IAST [baseline] (26.979 ms) : 0, 26979
IAST [candidate] (26.873 ms) : 0, 26873
section profiling
ProfilingAgent [baseline] (101.472 ms) : 0, 101472
ProfilingAgent [candidate] (99.788 ms) : 0, 99788
crashtracking [baseline] (1.235 ms) : 0, 1235
crashtracking [candidate] (1.215 ms) : 0, 1215
BytebuddyAgent [baseline] (687.174 ms) : 0, 687174
BytebuddyAgent [candidate] (678.281 ms) : 0, 678281
AgentMeter [baseline] (8.801 ms) : 0, 8801
AgentMeter [candidate] (8.681 ms) : 0, 8681
GlobalTracer [baseline] (219.552 ms) : 0, 219552
GlobalTracer [candidate] (216.971 ms) : 0, 216971
AppSec [baseline] (32.77 ms) : 0, 32770
AppSec [candidate] (32.067 ms) : 0, 32067
Debugger [baseline] (68.419 ms) : 0, 68419
Debugger [candidate] (68.05 ms) : 0, 68050
Remote Config [baseline] (610.155 µs) : 0, 610
Remote Config [candidate] (602.035 µs) : 0, 602
Telemetry [baseline] (8.912 ms) : 0, 8912
Telemetry [candidate] (8.795 ms) : 0, 8795
Flare Poller [baseline] (3.851 ms) : 0, 3851
Flare Poller [candidate] (3.853 ms) : 0, 3853
Profiling [baseline] (102.069 ms) : 0, 102069
Profiling [candidate] (100.37 ms) : 0, 100370
Startup time reports for insecure-bankgantt
title insecure-bank - global startup overhead: candidate=1.59.0-SNAPSHOT~3f18bf9da6, baseline=1.59.0-SNAPSHOT~02cc48359b
dateFormat X
axisFormat %s
section tracing
Agent [baseline] (1.066 s) : 0, 1066456
Total [baseline] (8.761 s) : 0, 8760649
Agent [candidate] (1.059 s) : 0, 1059429
Total [candidate] (8.736 s) : 0, 8736489
section iast
Agent [baseline] (1.225 s) : 0, 1225030
Total [baseline] (9.44 s) : 0, 9439646
Agent [candidate] (1.227 s) : 0, 1226675
Total [candidate] (9.405 s) : 0, 9405369
gantt
title insecure-bank - break down per module: candidate=1.59.0-SNAPSHOT~3f18bf9da6, baseline=1.59.0-SNAPSHOT~02cc48359b
dateFormat X
axisFormat %s
section tracing
crashtracking [baseline] (1.198 ms) : 0, 1198
crashtracking [candidate] (1.182 ms) : 0, 1182
BytebuddyAgent [baseline] (628.506 ms) : 0, 628506
BytebuddyAgent [candidate] (623.266 ms) : 0, 623266
AgentMeter [baseline] (28.938 ms) : 0, 28938
AgentMeter [candidate] (28.913 ms) : 0, 28913
GlobalTracer [baseline] (258.146 ms) : 0, 258146
GlobalTracer [candidate] (258.653 ms) : 0, 258653
AppSec [baseline] (33.045 ms) : 0, 33045
AppSec [candidate] (32.931 ms) : 0, 32931
Debugger [baseline] (61.87 ms) : 0, 61870
Debugger [candidate] (61.25 ms) : 0, 61250
Remote Config [baseline] (612.737 µs) : 0, 613
Remote Config [candidate] (610.425 µs) : 0, 610
Telemetry [baseline] (9.15 ms) : 0, 9150
Telemetry [candidate] (10.06 ms) : 0, 10060
Flare Poller [baseline] (9.231 ms) : 0, 9231
Flare Poller [candidate] (7.038 ms) : 0, 7038
section iast
crashtracking [baseline] (1.189 ms) : 0, 1189
crashtracking [candidate] (1.189 ms) : 0, 1189
BytebuddyAgent [baseline] (790.133 ms) : 0, 790133
BytebuddyAgent [candidate] (791.631 ms) : 0, 791631
AgentMeter [baseline] (11.172 ms) : 0, 11172
AgentMeter [candidate] (11.191 ms) : 0, 11191
GlobalTracer [baseline] (248.003 ms) : 0, 248003
GlobalTracer [candidate] (248.384 ms) : 0, 248384
IAST [baseline] (26.89 ms) : 0, 26890
IAST [candidate] (26.834 ms) : 0, 26834
AppSec [baseline] (32.224 ms) : 0, 32224
AppSec [candidate] (32.996 ms) : 0, 32996
Debugger [baseline] (67.348 ms) : 0, 67348
Debugger [candidate] (66.513 ms) : 0, 66513
Remote Config [baseline] (553.508 µs) : 0, 554
Remote Config [candidate] (538.453 µs) : 0, 538
Telemetry [baseline] (8.533 ms) : 0, 8533
Telemetry [candidate] (8.506 ms) : 0, 8506
Flare Poller [baseline] (3.467 ms) : 0, 3467
Flare Poller [candidate] (3.476 ms) : 0, 3476
LoadParameters
See matching parameters
SummaryFound 1 performance improvements and 0 performance regressions! Performance is the same for 18 metrics, 17 unstable metrics.
Request duration reports for petclinicgantt
title petclinic - request duration [CI 0.99] : candidate=1.59.0-SNAPSHOT~3f18bf9da6, baseline=1.59.0-SNAPSHOT~02cc48359b
dateFormat X
axisFormat %s
section baseline
no_agent (19.111 ms) : 18911, 19310
. : milestone, 19111,
appsec (18.711 ms) : 18520, 18903
. : milestone, 18711,
code_origins (17.765 ms) : 17590, 17940
. : milestone, 17765,
iast (17.716 ms) : 17538, 17894
. : milestone, 17716,
profiling (18.528 ms) : 18344, 18712
. : milestone, 18528,
tracing (17.497 ms) : 17325, 17668
. : milestone, 17497,
section candidate
no_agent (18.124 ms) : 17938, 18310
. : milestone, 18124,
appsec (18.537 ms) : 18348, 18726
. : milestone, 18537,
code_origins (17.392 ms) : 17220, 17564
. : milestone, 17392,
iast (17.464 ms) : 17290, 17637
. : milestone, 17464,
profiling (18.429 ms) : 18244, 18613
. : milestone, 18429,
tracing (17.431 ms) : 17259, 17604
. : milestone, 17431,
Request duration reports for insecure-bankgantt
title insecure-bank - request duration [CI 0.99] : candidate=1.59.0-SNAPSHOT~3f18bf9da6, baseline=1.59.0-SNAPSHOT~02cc48359b
dateFormat X
axisFormat %s
section baseline
no_agent (1.175 ms) : 1164, 1187
. : milestone, 1175,
iast (3.154 ms) : 3114, 3195
. : milestone, 3154,
iast_FULL (5.749 ms) : 5692, 5807
. : milestone, 5749,
iast_GLOBAL (3.576 ms) : 3522, 3630
. : milestone, 3576,
profiling (2.126 ms) : 2106, 2146
. : milestone, 2126,
tracing (1.794 ms) : 1780, 1809
. : milestone, 1794,
section candidate
no_agent (1.23 ms) : 1217, 1243
. : milestone, 1230,
iast (3.187 ms) : 3148, 3227
. : milestone, 3187,
iast_FULL (5.822 ms) : 5764, 5880
. : milestone, 5822,
iast_GLOBAL (3.451 ms) : 3396, 3505
. : milestone, 3451,
profiling (1.93 ms) : 1913, 1946
. : milestone, 1930,
tracing (1.807 ms) : 1790, 1823
. : milestone, 1807,
DacapoParameters
See matching parameters
SummaryFound 0 performance improvements and 0 performance regressions! Performance is the same for 10 metrics, 2 unstable metrics. Execution time for biojavagantt
title biojava - execution time [CI 0.99] : candidate=1.59.0-SNAPSHOT~3f18bf9da6, baseline=1.59.0-SNAPSHOT~02cc48359b
dateFormat X
axisFormat %s
section baseline
no_agent (14.873 s) : 14873000, 14873000
. : milestone, 14873000,
appsec (15.072 s) : 15072000, 15072000
. : milestone, 15072000,
iast (18.83 s) : 18830000, 18830000
. : milestone, 18830000,
iast_GLOBAL (17.833 s) : 17833000, 17833000
. : milestone, 17833000,
profiling (15.427 s) : 15427000, 15427000
. : milestone, 15427000,
tracing (15.164 s) : 15164000, 15164000
. : milestone, 15164000,
section candidate
no_agent (14.916 s) : 14916000, 14916000
. : milestone, 14916000,
appsec (14.744 s) : 14744000, 14744000
. : milestone, 14744000,
iast (18.195 s) : 18195000, 18195000
. : milestone, 18195000,
iast_GLOBAL (17.724 s) : 17724000, 17724000
. : milestone, 17724000,
profiling (15.463 s) : 15463000, 15463000
. : milestone, 15463000,
tracing (14.832 s) : 14832000, 14832000
. : milestone, 14832000,
Execution time for tomcatgantt
title tomcat - execution time [CI 0.99] : candidate=1.59.0-SNAPSHOT~3f18bf9da6, baseline=1.59.0-SNAPSHOT~02cc48359b
dateFormat X
axisFormat %s
section baseline
no_agent (1.481 ms) : 1469, 1492
. : milestone, 1481,
appsec (3.724 ms) : 3506, 3943
. : milestone, 3724,
iast (2.266 ms) : 2196, 2335
. : milestone, 2266,
iast_GLOBAL (2.319 ms) : 2248, 2389
. : milestone, 2319,
profiling (2.505 ms) : 2341, 2669
. : milestone, 2505,
tracing (2.084 ms) : 2030, 2138
. : milestone, 2084,
section candidate
no_agent (1.477 ms) : 1466, 1489
. : milestone, 1477,
appsec (3.703 ms) : 3487, 3920
. : milestone, 3703,
iast (2.256 ms) : 2187, 2324
. : milestone, 2256,
iast_GLOBAL (2.303 ms) : 2233, 2372
. : milestone, 2303,
profiling (2.094 ms) : 2038, 2150
. : milestone, 2094,
tracing (2.062 ms) : 2009, 2116
. : milestone, 2062,
|
| @@ -114,7 +115,7 @@ public static final class ClientResponseAdvice { | |||
| public static ContextScope beginResponse( | |||
| @Advice.Argument(0) final NHttpClientConnection connection) { | |||
| // check and remove context so it won't be finished twice | |||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Can you update this comment to match the new approach?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Fixed
| @@ -93,7 +94,7 @@ public static final class ServerResponseAdvice { | |||
| public static ContextScope beginResponse( | |||
| @Advice.Argument(0) final NHttpServerConnection connection) { | |||
| // check and remove context so it won't be finished twice | |||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Also update this comment to match the new approach
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Fixed
What Does This Do
Fixed flaky Synapse passthru tracing by changing when we finish the HTTP span.
responseReadyandresponseReceivedmay be called before theHttpResponse(and status code) is available.Instead of removing the stored context and finish span of the first callback, we keep the context until we see the real response status (or error), then finish the span once.
Motivation
Test
test passthru request is tracedwas sometimes failing with, because the span was finishing too early, before status code was knownAdditional Notes
With the passthru/NIO transport,
SourceHandler.responseReady()andTargetHandler.responseReceived()can be called multiple times for the same connectionThe first call can happen while the response is still null, and the actual 200 OK is set later.
Previously we removed the context and finished the span on that first call, so the later callback couldn’t tag the span
Contributor Checklist
type:and (comp:orinst:) labels in addition to any useful labelsclose,fixor any linking keywords when referencing an issue.Use
solvesinstead, and assign the PR milestone to the issueJira ticket: [PROJ-IDENT]