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

Figure out why Caddy isn't using sendfile #4731

Closed
mholt opened this issue Apr 26, 2022 · 16 comments · Fixed by #5022
Closed

Figure out why Caddy isn't using sendfile #4731

mholt opened this issue Apr 26, 2022 · 16 comments · Fixed by #5022
Labels
bug 🐞 Something isn't working help wanted 🆘 Extra attention is needed
Milestone

Comments

@mholt
Copy link
Member

mholt commented Apr 26, 2022

Context:

Caddy should use Unix sendfile when there's no TLS and no compression. (And even for TLS, we should look into kTLS. But maybe unsafe, sigh.)

@mholt mholt added the bug 🐞 Something isn't working label Apr 26, 2022
@mholt mholt added this to the 2.x milestone Apr 26, 2022
@francislavoie
Copy link
Member

Found this: https://www.reddit.com/r/golang/comments/b9ewko/comment/hphp294/?utm_source=reddit&utm_medium=web2x&context=3

(Sorry @mohammed90 😅) - We use http.ServeContent which calls io.CopyN, and that wraps the src Reader in a io.LimitedReader which isn't an *os.File, so sendfile doesn't trigger 😢

@francislavoie
Copy link
Member

There was an attempt to fix it here many years ago, went inactive: https://go-review.googlesource.com/c/go/+/7893/3

@flga
Copy link
Collaborator

flga commented Sep 6, 2022

so sendfile doesn't trigger

It should, ReadFrom will unconditionally* invoke sendFile which unwraps the LimitReader.

*However this will only apply if the file is larger than 512 bytes as the first 512 byte chunk is explicitly handled before triggering sendfile.

I can reproduce this behaviour with bare net/http so the problem is either in the size of the test files, or something else is missing from the equation.

Looking briefly at the file server I don't see any major red flags that would invalidate this, but it's late I'll have a proper look tomorrow night.

@mholt
Copy link
Member Author

mholt commented Sep 6, 2022

@flga Ohh, thank you for looking into this. This kernel stuff goes a little over my head "kerrantly" 🙃

I don't know how to debug this in Caddy; specifically, I've never used strace for anything more complicated than a hello-world-style C program, so maybe having confirmation that sendfile() isn't being called would be a good start.

A test config might look like this:

:80

root ./sendfile_test
file_server

That's HTTP-only, and no encode directive means no compression, so I would expect sendfile to work here.

Or, without using a config file:

$ caddy file-server --root ./sendfile_test

I would also expect that to use sendfile when serving up files.

It would be absolutely awesome if you had a chance to dig into this and help us figure out how to get sendfile to be used (even on TLS*).

  • We might be able to get sendfile working over TLS with a setsockopt() call from what I've read.

@mholt mholt added the help wanted 🆘 Extra attention is needed label Sep 6, 2022
@flga
Copy link
Collaborator

flga commented Sep 6, 2022

Took a peek during lunch, sendfile is indeed not being called in caddy and the reason is that the response writer received in the file server is not a vanilla http responsewriter, it's an instance of our own ResponseRecorder. This type hides the ReadFrom method from io.Copy so the sendfile behaviour is never even considered. Doing a quick & dirty patch so that it exposes ReadFrom causes sendfile to be used again as expected.

ResponseWriterWrapper suffers from the same issue, it's effectively hiding some upgrade interfaces tho it's not clear to me how impactful that is or if it is even relevant given we support the major ones like Flusher.

Anyway, this was just a quick dirty gut check, I'll need to look at the code a little closer to see where best to spend our efforts.

re TLS: I'm not sure this is worth pursuing, it seems to me we would be fighting against net/http and crypto/tls the whole way so the gains would have to be huge in order to be worth it. A quick search for ktls in the go repo came up with this: golang/go#44506 and a related post from Fillo https://words.filippo.io/playing-with-kernel-tls-in-linux-4-13-and-go/
That said it merits a deeper look, even if it does prove to not be worth it, so I'll try to fit it in soon.

@mholt
Copy link
Member Author

mholt commented Sep 6, 2022

D'oh, I totally forgot that we wrap all the ResponseWriters with our own recorder type so that we can provide logging:

if s.shouldLogRequest(r) {
wrec := NewResponseRecorder(w, nil, nil)
w = wrec

Doing a quick & dirty patch so that it exposes ReadFrom causes sendfile to be used again as expected.

That's actually pretty reasonable, I would be happy to review that patch!

ResponseWriterWrapper suffers from the same issue, it's effectively hiding some upgrade interfaces tho it's not clear to me how impactful that is or if it is even relevant given we support the major ones like Flusher.

I wish I knew a better way to wrap the response writer without having to implement all these interfaces, but clearly we are missing some. Again, I'd be happy to add it there, as the purpose of this wrapper type is to make it function like the underlying type.

Re: kTLS, I'm OK with it if we defer/shelve that for now, but if you feel like hacking on it just to see a PoC, I won't stop you! Depending on how aggregious it is (haha) we might not merge it, but if you want to have some fun then go ahead. If it turns out reasonable maybe we can even merge it.

Thanks for looking into things!

@stapelberg
Copy link
Contributor

I wish I knew a better way to wrap the response writer without having to implement all these interfaces, but clearly we are missing some. Again, I'd be happy to add it there, as the purpose of this wrapper type is to make it function like the underlying type.

You can read more about this problem in https://blog.merovius.de/posts/2017-07-30-the-trouble-with-optional-interfaces/

@flga flga closed this as completed in #5022 Sep 7, 2022
flga added a commit that referenced this issue Sep 7, 2022
…From if the underlying response writer implements it. (#5022)

Doing so allows for splice/sendfile optimizations when available.
Fixes #4731

Co-authored-by: flga <flga@users.noreply.github.com>
Co-authored-by: Matthew Holt <mholt@users.noreply.github.com>
@baryluk
Copy link

baryluk commented Sep 8, 2022

@flga @mholt Thanks a lot.

@zekjur @stapelberg Should we retest on 25Gbps again with new caddy? :D

@stapelberg
Copy link
Contributor

@zekjur @stapelberg Should we retest on 25Gbps again with new caddy? :D

I just updated caddy on my router, so feel free to give it a shot.

I did some tests in my local network, but found no measurable difference — caddy was reaching 25 Gbit/s before and after :) (see also: https://michael.stapelberg.ch/posts/2022-05-14-http-and-https-download-25gbit/)

@mholt
Copy link
Member Author

mholt commented Sep 8, 2022

@stapelberg Any latency improvements? Even if it's saturating the network I would expect lower latency (TTFB). Make sure your test payload is large enough too.

@stapelberg
Copy link
Contributor

I wouldn’t expect the TTFB to be any lower, as the few buffer allocations should be immeasurably quick. Only if you do larger transfers for longer does it add up.

Did you see any TTFB improvements in your tests? Can you share the payload you used, and with which tool you measured?

@mholt
Copy link
Member Author

mholt commented Sep 8, 2022

@stapelberg I did see lower latency, but I was just testing on the loopback interface.

My payload and test procedure was very simple, as documented in the linked PR (#5022) -- you can see charts and stats and program output there!

You might want to use an even larger payload on such a high-bandwidth interface. But I'm not sure, maybe that's enough!

@stapelberg
Copy link
Contributor

Before patch (commit 1c9c8f6):

% wrk -t12 -c400 -d10s http://repo7.distr1.org/   
Running 10s test @ http://repo7.distr1.org/
  12 threads and 400 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    27.08ms   36.39ms 360.20ms   83.76%
    Req/Sec     3.11k   597.97    13.09k    79.47%
  373684 requests in 10.10s, 81.25MB read
Requests/sec:  37000.24
Transfer/sec:      8.05MB

After patch:

% wrk -t12 -c400 -d10s http://repo7.distr1.org/
Running 10s test @ http://repo7.distr1.org/
  12 threads and 400 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency    27.42ms   37.02ms 401.90ms   83.67%
    Req/Sec     3.14k   637.75    16.27k    83.77%
  377823 requests in 10.10s, 82.15MB read
Requests/sec:  37410.36
Transfer/sec:      8.13MB

As I expected, I don’t see a significant change in latency. With an 83% standard deviation, there is quite a bit of noise in this measurement anyway.

@mholt
Copy link
Member Author

mholt commented Sep 9, 2022

Yeah, I think once you get bandwidth that high, tests like this are a little tricky to find reliable.

Still cool if it's saturating your link though!

@terrywh
Copy link

terrywh commented Aug 27, 2024

still cannot use sendfile() in a http handler:

file, _ := os.Open("file")
w.(io.ReaderFrom).ReadFrom(file) 

OR

file, _ := os.Open("file")
file.WriteTo(w)

either way the sendfile / splice will not be called for the following reason:

  1. caddyhttp.ResponseRecorder does not implement syscall.Conn (zero_copy_linux.go:126)
  2. file *os.Filegot wrapped in os.fileWithoutWriteTo (file.go:269)
  3. (*http.response) ReadFrom()/sendfile() try to use TCPConn.ReadFrom but src is not a *os.File (sendfile_linux_go:20)
  4. fallback to genericReadFrom() (tcpsock_posix.go:54)
    (above go v1.22.5 )

@stapelberg @mholt @flga @francislavoie can any one help me on how can i streaming a file using sendfile()?

@mholt
Copy link
Member Author

mholt commented Aug 27, 2024

@terrywh If you could please open a new issue to report a bug, or use the forums to request help. Thank you! (We'll need enough code, minimally-reproducible example to recreate the issue.)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug 🐞 Something isn't working help wanted 🆘 Extra attention is needed
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants