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

Perf regression in the HTTP parser caused by long look-ahead #11513

Closed
lorban opened this issue Mar 13, 2024 · 11 comments · Fixed by #11517
Closed

Perf regression in the HTTP parser caused by long look-ahead #11513

lorban opened this issue Mar 13, 2024 · 11 comments · Fixed by #11517
Assignees
Labels
Bug For general bugs on Jetty side Performance
Milestone

Comments

@lorban
Copy link
Contributor

lorban commented Mar 13, 2024

Jetty version(s)
12.0.x

Description
The changes in #11486 introduced a noticeable performance regression.

This profiler run was executed against branch 12.0.x and clearly shows that the GC is very busy.

While that profiler run was executed against branch experiment/jetty-12/revert-11486 with the only difference being the changes of #11486 were reverted, and it shows the GC is doing a lot less work.

@gregw
Copy link
Contributor

gregw commented Mar 13, 2024

@lorban Interesting, as there was good improvements in jmh including gc. But let's roll back for this release and evaluate which of the optimisations work and which do not. Maybe I implemented wrongly as compared with the jmh?

Strange that there is more allocation as the idea is that there should be none?

@lorban
Copy link
Contributor Author

lorban commented Mar 13, 2024

First clues of what's going on:

Allocation prof with long look-ahead vs Allocation prof without long look-ahead

Zoom on HttpParser.parseFields() and you'll notice that HttpParser.parsedHeader() (9.97% vs 1.56%) and HttpParser.takeString() (4.91% vs 9.68%) allocate more with long look-ahead while allocations in RequestHandler.headerComplete() stay rather constant (18.07% vs 19.88%).

@sbordet
Copy link
Contributor

sbordet commented Mar 13, 2024

@lorban seem like the 2 runs run different code... can you double check?

@gregw
Copy link
Contributor

gregw commented Mar 13, 2024

@lorban Something is strange with that, because the changes should not have affected parseFields(), as they were almost all in quickStart, which is used for the request/response line rather than parsing fields. At least that was the part that was JMH tested... maybe I snuck in something else untested.... looking....

@lorban
Copy link
Contributor Author

lorban commented Mar 13, 2024

@gregw
Copy link
Contributor

gregw commented Mar 13, 2024

@lorban I can't see any significant changes in parseFields(), but in your flamegraphs, there is a lot of allocating of HostPortHttpField happening... so something has changed!

I'm guess the issue is that the quick start method might not be setting things up right for the Host header caching to work.

@gregw
Copy link
Contributor

gregw commented Mar 13, 2024

@lorban same thing in your second run. The code with long lookahead is allocating HostPortHttpFields in parseFields, whilst the original code is not??

@lorban
Copy link
Contributor Author

lorban commented Mar 13, 2024

@gregw I cannot explain it yet, but this is the data we have.

Clearly, latencies suffered, CPU profiling shows the GC is overworked so I think the allocation profile we have can be trusted... unless proven otherwise.

I'll work top-down and add some stat counters to try to understand what's going on.

@gregw
Copy link
Contributor

gregw commented Mar 13, 2024

@lorban found it! The new quick start paths are missing _fieldCache.prepare();, which is done by the normal requestLine parsing! So we are not caching host headers (or other for that matter) and will be creating lots of new ones. It should be a simple fix.... let me prepare a branch....

gregw added a commit that referenced this issue Mar 13, 2024
Fix #11513 by preparing the field cache
@gregw
Copy link
Contributor

gregw commented Mar 13, 2024

@lorban can you test #11517?

@lorban
Copy link
Contributor Author

lorban commented Mar 13, 2024

@gregw you nailed it, the cpu profiling of #11517 shows that the GC is now back to its normal activity.

gregw added a commit that referenced this issue Mar 13, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug For general bugs on Jetty side Performance
Projects
No open projects
Status: ✅ Done
Development

Successfully merging a pull request may close this issue.

3 participants