Detecting temp directory performed on every request
Hello. I was benchmarking wisp and mist, I saw that wisp is significantly slower. Found that applying following diff to make_connection and wisp_mist.handler is making wisp 20x faster on linux (wsl).
pub fn make_connection(
body_reader: Reader,
secret_key_base: String,
) -> Connection {
// Fallback to current working directory when no valid tmp directory exists
- let prefix = case directories.tmp_dir() {
- Ok(tmp_dir) -> tmp_dir <> "/gleam-wisp/"
- Error(_) -> "./tmp/"
- }
- let temporary_directory = join_path(prefix, random_slug())
+ let temporary_directory = "test"
Connection(
reader: body_reader,
max_body_size: 8_000_000,
max_files_size: 32_000_000,
read_chunk_size: 1_000_000,
temporary_directory: temporary_directory,
secret_key_base: secret_key_base,
)
}
pub fn handler(
handler: fn(wisp.Request) -> wisp.Response,
secret_key_base: String,
) -> fn(HttpRequest(mist.Connection)) -> HttpResponse(mist.ResponseData) {
fn(request: HttpRequest(_)) {
let connection =
internal.make_connection(mist_body_reader(request), secret_key_base)
let request = request.set_body(request, connection)
+ // todo: try to delete temporary files only if they have been allocated for this request?
- use <- exception.defer(fn() {
- let assert Ok(_) = wisp.delete_temporary_files(request)
- })
let response =
request
|> handler
|> mist_response
response
}
}
Current wisp version:
Running 1s test @ http://127.0.0.1:8000
6 threads and 100 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 3.95ms 404.93us 5.37ms 72.56%
Req/Sec 4.05k 295.12 4.69k 73.33%
24198 requests in 1.00s, 2.61MB read
Requests/sec: 24165.91
Transfer/sec: 2.60MB
With following path:
wrk -c 100 -d 1 -t 6 http://127.0.0.1:8000
Running 1s test @ http://127.0.0.1:8000
6 threads and 100 connections
Thread Stats Avg Stdev Max +/- Stdev
Latency 274.09us 507.14us 9.34ms 93.26%
Req/Sec 83.83k 15.16k 105.48k 63.08%
541738 requests in 1.10s, 58.38MB read
Requests/sec: 492452.83
Transfer/sec: 53.07MB
I think it would be better to do it lazily (only when needed) since looking up temp directory (directories.tmp_dir()) to check if file exists to never use that in handler is too expensive.
I would be happy to PR laziness, but I don't know really how to make that yet, I'm a new gleamer...
Was the the finding of the temp directory or the generation of the slug that was source of the problem?
What does your handler do your benchmark?
What was the time cost per request?
Was the the finding of the temp directory or the generation of the slug that was source of the problem?
directories.tmp_dir() is source of the problem, because it asks OS for file information to make sure given temp path is a directory. The same applies to wisp.delete_temporary_files, which always makes an expensive syscall.
What does your handler do your benchmark?
wisp_mist.handler(
fn(_req) {
wisp.response(200)
|> wisp.set_body(wisp.Text(string_builder.from_string("Hello, world")))
},
"secret",
)
|> mist.new
|> mist.port(8000)
|> mist.start_http
What was the time cost per request?
current version
user@desktop:~$ curl -o /dev/null -s -w 'Total: %{time_total}s\n' http://localhost:8000
Total: 0.000643s
user@desktop:~$ curl -o /dev/null -s -w 'Total: %{time_total}s\n' http://localhost:8000
Total: 0.000671s
user@desktop:~$ curl -o /dev/null -s -w 'Total: %{time_total}s\n' http://localhost:8000
Total: 0.000611s
user@desktop:~$ curl -o /dev/null -s -w 'Total: %{time_total}s\n' http://localhost:8000
Total: 0.000744s
user@desktop:~$ curl -o /dev/null -s -w 'Total: %{time_total}s\n' http://localhost:8000
Total: 0.000763s
user@desktop:~$ curl -o /dev/null -s -w 'Total: %{time_total}s\n' http://localhost:8000
Total: 0.000622s
user@desktop:~$ curl -o /dev/null -s -w 'Total: %{time_total}s\n' http://localhost:8000
Total: 0.000675s
without temp directories:
user@desktop:~$ curl -o /dev/null -s -w 'Total: %{time_total}s\n' http://localhost:8000
Total: 0.000509s
user@desktop:~$ curl -o /dev/null -s -w 'Total: %{time_total}s\n' http://localhost:8000
Total: 0.000448s
user@desktop:~$ curl -o /dev/null -s -w 'Total: %{time_total}s\n' http://localhost:8000
Total: 0.000465s
user@desktop:~$ curl -o /dev/null -s -w 'Total: %{time_total}s\n' http://localhost:8000
Total: 0.000396s
It's more impactful on high load.
Is there recommended way to profile gleam program?
So it is about a cost of ~0.2ms per request?
If that's the case it may be that this would not be measurable with a real application that doesn't return immediately with a fixed value in the handler. In this benchmark it's only work being performed, so removing it has a large proportional impact on the results.
Moving the tmp directory discovery to the application initialiser rather than per request sounds sensible.
So it is about a cost of ~0.2ms per request?
For single request, it looks like. Latency increases a lot under high pressure (as results from wrk results from original post shows). I'm running this bench on a beefy pc (with fast m2 990 pro ssd) so the results may not be that critical in my case. Additional layers between gleam program and OS like virtualization (running on a vps) and containerization (docker) can also impact that.
Moving the tmp directory discovery to the application initialiser rather than per request sounds sensible.
Will it solve unnecessary wisp.delete_temporary_files(request) call?
A useful test would be to write a more realistic application that uses all of Wisp's middleware, decodes and encodes a handful of kb of JSON, and reads and writes to a database or some files. That would give a better understanding of the impact. The current data suggests it is not a good area to try and optimise.
Moving the tmp directory detection to the initialiser would not remove the need for cleanup, no.
Yeah, but 25k requests per second on latest gen cpu with 32 threads is in my "real application" total no go. I understand most real world applications are frontends for database, but unfortunately not in my case. I think using raw mist would be fine for me, but I'm scared that any day it will end up as solution only for cruds. https://github.com/gleam-wisp/wisp/issues/60 is misleading