Figure out why Caddy isn't using sendfile

[mholt]

Context:

• https://twitter.com/WBaryluk/status/1519019831651180544
• https://twitter.com/WBaryluk/status/1519019570140434432

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.)

[francislavoie]

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]

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

[flga]

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]

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

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.

[flga]

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: https://github.com/golang/go/issues/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]

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

https://github.com/caddyserver/caddy/blob/8cc8f9fddd2ea717633528322e1bef938bee2415/modules/caddyhttp/server.go#L221-L223

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]

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/

[baryluk]

@flga @mholt Thanks a lot.

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

[stapelberg]

@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]

@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]

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]

@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]

Before patch (commit 1c9c8f6a13f99817cb35a9b100287da81255be21):

% 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]

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!