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

fix(http3): always qlog on send_buffer() #1876

Merged
merged 6 commits into from
May 6, 2024

Conversation

mxinden
Copy link
Collaborator

@mxinden mxinden commented May 3, 2024

neqo_http3::SendMessage calls qlog::h3_data_moved_down() whenever it moves data down to the QUIC layer. SendMessage moves data down to the QUIC layer either directly via self.stream.send_atomic or indirectly buffered through self.stream.send_buffer.

Previously only one of the 3 calls to self.stream.send_buffer would thereafter call qlog::h3_data_moved_down().

Calls missing the follow-up qlog call:

This commit moves the h3_data_moved_down call into self.stream.send_buffer, thus ensuring the function is always called when data is moved. In addition, self.stream.send_atomic now as well does the qlog call, thus containing all qlog logic in buffered_send_stream.rs instead of send_message.rs.

`neqo_http3::SendMessage` calls `qlog::h3_data_moved_down()` whenever it moves
data down to the QUIC layer. `SendMessage` moves data down to the QUIC layer
either directly via `self.stream.send_atomic` or indirectly buffered through `self.stream.send_buffer`.

Previously only one of the 3 calls to `self.stream.send_buffer` would thereafter
call `qlog::h3_data_moved_down()`.

This commit moves the `h3_data_moved_down` call into `self.stream.send_buffer`, thus
ensuring the function is always called when data is moved. In addition,
`self.stream.send_atomic` now as well does the qlog call, thus containing all
qlog logic in `buffered_send_stream.rs` instead of `send_message.rs`.
Copy link

github-actions bot commented May 3, 2024

Failed Interop Tests

QUIC Interop Runner, client vs. server

All results

Succeeded Interop Tests

QUIC Interop Runner, client vs. server

Unsupported Interop Tests

QUIC Interop Runner, client vs. server

Copy link

github-actions bot commented May 3, 2024

Benchmark results

Performance differences relative to ed19eb2.

  • drain a timer quickly time: [320.00 ns 327.50 ns 334.48 ns]
    change: [+1.5858% +3.7835% +5.8476%] (p = 0.00 < 0.05)
    💔 Performance has regressed.

  • coalesce_acked_from_zero 1+1 entries
    time: [199.47 ns 199.99 ns 200.55 ns]
    change: [+0.4481% +0.7992% +1.1456%] (p = 0.00 < 0.05)
    Change within noise threshold.

  • coalesce_acked_from_zero 3+1 entries
    time: [246.13 ns 246.77 ns 247.48 ns]
    change: [+2.2781% +2.5709% +2.8685%] (p = 0.00 < 0.05)
    💔 Performance has regressed.

  • coalesce_acked_from_zero 10+1 entries
    time: [244.00 ns 244.49 ns 245.16 ns]
    change: [+0.8987% +1.3567% +1.7610%] (p = 0.00 < 0.05)
    Change within noise threshold.

  • coalesce_acked_from_zero 1000+1 entries
    time: [226.23 ns 226.60 ns 227.05 ns]
    change: [+4.3458% +4.9743% +5.5953%] (p = 0.00 < 0.05)
    💔 Performance has regressed.

  • RxStreamOrderer::inbound_frame()
    time: [118.67 ms 118.74 ms 118.82 ms]
    change: [-0.3603% -0.2768% -0.1993%] (p = 0.00 < 0.05)
    Change within noise threshold.

  • transfer/Run multiple transfers with varying seeds
    time: [118.64 ms 118.93 ms 119.23 ms]
    thrpt: [33.549 MiB/s 33.632 MiB/s 33.716 MiB/s]
    change:
    time: [-1.4741% -1.1518% -0.7996%] (p = 0.00 < 0.05)
    thrpt: [+0.8061% +1.1652% +1.4962%]
    Change within noise threshold.

  • transfer/Run multiple transfers with the same seed
    time: [119.16 ms 119.37 ms 119.57 ms]
    thrpt: [33.452 MiB/s 33.510 MiB/s 33.569 MiB/s]
    change:
    time: [-1.3776% -1.1186% -0.8649%] (p = 0.00 < 0.05)
    thrpt: [+0.8725% +1.1312% +1.3969%]
    Change within noise threshold.

  • 1-conn/1-100mb-resp (aka. Download)/client
    time: [1.1102 s 1.1161 s 1.1224 s]
    thrpt: [89.096 MiB/s 89.599 MiB/s 90.074 MiB/s]
    change:
    time: [+1.0964% +1.8801% +2.6351%] (p = 0.00 < 0.05)
    thrpt: [-2.5674% -1.8454% -1.0846%]
    💔 Performance has regressed.

  • 1-conn/10_000-parallel-1b-resp (aka. RPS)/client
    time: [424.52 ms 426.49 ms 428.46 ms]
    thrpt: [23.339 Kelem/s 23.447 Kelem/s 23.556 Kelem/s]
    change:
    time: [-0.8987% -0.1826% +0.5147%] (p = 0.59 > 0.05)
    thrpt: [-0.5121% +0.1829% +0.9068%]
    No change in performance detected.

  • 1-conn/1-1b-resp (aka. HPS)/client
    time: [49.397 ms 49.653 ms 49.856 ms]
    thrpt: [20.058 elem/s 20.140 elem/s 20.244 elem/s]
    change:
    time: [-2.1227% -1.3731% -0.7062%] (p = 0.00 < 0.05)
    thrpt: [+0.7112% +1.3923% +2.1688%]
    Change within noise threshold.

Client/server transfer results

Transfer of 134217728 bytes over loopback.

Client Server CC Pacing Mean [ms] Min [ms] Max [ms] Relative
msquic msquic 740.1 ± 254.5 403.7 1072.2 1.00
neqo msquic reno on 1084.0 ± 411.5 781.4 1893.9 1.00
neqo msquic reno 910.6 ± 250.7 732.3 1593.5 1.00
neqo msquic cubic on 1023.3 ± 298.4 771.7 1551.7 1.00
neqo msquic cubic 993.6 ± 172.9 791.8 1328.4 1.00
msquic neqo reno on 4457.3 ± 234.9 4139.2 4862.7 1.00
msquic neqo reno 4361.8 ± 196.6 4000.3 4683.5 1.00
msquic neqo cubic on 4488.8 ± 270.7 4162.0 5067.9 1.00
msquic neqo cubic 4440.4 ± 224.8 4157.6 4884.4 1.00
neqo neqo reno on 3807.5 ± 365.2 3274.8 4502.0 1.00
neqo neqo reno 3523.7 ± 364.8 2663.2 3885.6 1.00
neqo neqo cubic on 4185.0 ± 371.9 3291.8 4724.4 1.00
neqo neqo cubic 4100.0 ± 458.9 2904.9 4647.1 1.00

⬇️ Download logs

@larseggert
Copy link
Collaborator

Performance regression?

@mxinden
Copy link
Collaborator Author

mxinden commented May 3, 2024

  • 1-conn/1-100mb-resp (aka. Download)/client
    time: [1.3130 s 1.3591 s 1.4076 s]
    thrpt: [71.045 MiB/s 73.576 MiB/s 76.164 MiB/s]
    change:
    time: [+19.860% +24.068% +28.069%] (p = 0.00 < 0.05)
    thrpt: [-21.917% -19.399% -16.569%]
    💔 Performance has regressed.

  • 1-conn/10_000-parallel-1b-resp (aka. RPS)/client
    time: [459.86 ms 468.06 ms 476.81 ms]
    thrpt: [20.973 Kelem/s 21.365 Kelem/s 21.746 Kelem/s]
    change:
    time: [+7.5555% +9.5455% +11.484%] (p = 0.00 < 0.05)
    thrpt: [-10.301% -8.7138% -7.0248%]
    💔 Performance has regressed.

That is surprising, given that qlog is disabled on both client and server.

qlog_dir: None,

Will investigate.

Copy link

codecov bot commented May 3, 2024

Codecov Report

All modified and coverable lines are covered by tests ✅

Project coverage is 93.24%. Comparing base (ed19eb2) to head (001666a).

Additional details and impacted files
@@           Coverage Diff           @@
##             main    #1876   +/-   ##
=======================================
  Coverage   93.24%   93.24%           
=======================================
  Files         110      110           
  Lines       35810    35811    +1     
=======================================
+ Hits        33390    33391    +1     
  Misses       2420     2420           

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

@mxinden
Copy link
Collaborator Author

mxinden commented May 4, 2024

  • 1-conn/1-100mb-resp (aka. Download)/client
    time: [1.0842 s 1.0964 s 1.1092 s]
    thrpt: [90.158 MiB/s 91.211 MiB/s 92.231 MiB/s]
    change:
    time: [-1.1129% +0.0795% +1.4091%] (p = 0.91 > 0.05)
    thrpt: [-1.3895% -0.0794% +1.1254%]
    No change in performance detected.

  • 1-conn/10_000-parallel-1b-resp (aka. RPS)/client
    time: [426.27 ms 428.31 ms 430.41 ms]
    thrpt: [23.234 Kelem/s 23.348 Kelem/s 23.460 Kelem/s]
    change:
    time: [-0.4397% +0.2432% +0.9176%] (p = 0.49 > 0.05)
    thrpt: [-0.9093% -0.2426% +0.4417%]
    No change in performance detected.

Consecutive run, without any changes, shows no regressions.

@mxinden
Copy link
Collaborator Author

mxinden commented May 4, 2024

d15e3e0 replaces the nested ifs with non-nested early returns. Just a suggestion. Happy to revert.

@mxinden
Copy link
Collaborator Author

mxinden commented May 4, 2024

I don't think the performance regressions seen in the first run are related. @larseggert mind giving this pull request a review?

@larseggert larseggert added this pull request to the merge queue May 6, 2024
Merged via the queue into mozilla:main with commit e467273 May 6, 2024
47 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants