Here's an example service with max_connections
set to 2 and backlog
of 16 (actix-web
v3.3.0):
const MAX_CONNECTIONS: usize = 2;
const BACKLOG: i32 = 16;
const WORKERS: usize = 1;
const ADDR: &str = "127.0.0.1:8888";
#[actix_web::main]
async fn main() -> std::io::Result<()> {
simplelog::CombinedLogger::init(vec![simplelog::TermLogger::new(
simplelog::LevelFilter::Info,
simplelog::Config::default(),
simplelog::TerminalMode::Stderr,
)])
.expect("logging configuration failed");
log::info!(
"Running server with {} workers / {} max connections / {} listen backlog on {}",
WORKERS,
MAX_CONNECTIONS,
BACKLOG,
ADDR
);
actix_web::HttpServer::new(move || {
actix_web::App::new().route("/", actix_web::web::get().to(greet))
})
.on_connect(move |_, _| {
log::info!(
"number of open fds = {}",
procfs::process::Process::myself()
.expect("creating procfs reader failed")
.fd_count()
.expect("getting fd count failed")
)
})
.max_connections(MAX_CONNECTIONS)
.backlog(BACKLOG)
.workers(WORKERS)
.bind(ADDR)?
.run()
.await
}
async fn greet() -> impl actix_web::Responder {
"howdy!\n"
}
One can run it:
$ cargo run
And then use the following go program to create one connection every 100ms without any requests:
package main
import (
"log"
"net"
"time"
)
func main() {
i := 0
for {
i++
_, err := net.Dial("tcp", "127.0.0.1:8888")
if err != nil {
log.Fatalf("Connection #%d failed: %s", i, err)
}
log.Printf("Connnection #%d succeded", i)
time.Sleep(time.Millisecond * 100)
}
}
The go program will happily churn until the end of ulimit.
What I expect from Actix is to not have more than 2 (limit) + 16 (backlog) connections open at any point, which corresponds to 22 open file descriptors (let's say under 30 for simplicity). What I see is that number gets a lot higher:
01:32:00 [INFO] Running server with 1 workers / 2 max connections / 16 listen backlog on 127.0.0.1:8888
01:32:00 [INFO] Starting 1 workers
01:32:00 [INFO] Starting "actix-web-service-127.0.0.1:8888" service on 127.0.0.1:8888
01:32:06 [INFO] number of open fds = 21
01:32:06 [INFO] number of open fds = 22
01:32:11 [INFO] number of open fds = 23
01:32:11 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:32:11 [INFO] number of open fds = 22
01:32:16 [INFO] number of open fds = 39
01:32:16 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:32:16 [INFO] number of open fds = 38
01:32:21 [INFO] number of open fds = 54
01:32:21 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:32:21 [INFO] number of open fds = 53
01:32:26 [INFO] number of open fds = 69
01:32:26 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:32:26 [INFO] number of open fds = 68
01:32:31 [INFO] number of open fds = 79
01:32:31 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:32:31 [INFO] number of open fds = 78
01:32:36 [INFO] number of open fds = 94
01:32:36 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:32:36 [INFO] number of open fds = 93
01:32:41 [INFO] number of open fds = 103
01:32:41 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:32:41 [INFO] number of open fds = 102
01:32:46 [INFO] number of open fds = 118
01:32:46 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:32:46 [INFO] number of open fds = 117
01:32:51 [INFO] number of open fds = 128
01:32:51 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:32:51 [INFO] number of open fds = 127
01:32:56 [INFO] number of open fds = 143
01:32:56 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:32:56 [INFO] number of open fds = 142
01:33:01 [INFO] number of open fds = 153
01:33:01 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:33:01 [INFO] number of open fds = 152
01:33:06 [INFO] number of open fds = 168
01:33:06 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:33:06 [INFO] number of open fds = 167
01:33:11 [INFO] number of open fds = 177
01:33:11 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:33:11 [INFO] number of open fds = 176
01:33:16 [INFO] number of open fds = 192
01:33:16 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:33:16 [INFO] number of open fds = 191
01:33:21 [INFO] number of open fds = 202
01:33:21 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:33:21 [INFO] number of open fds = 201
01:33:26 [INFO] number of open fds = 217
01:33:26 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:33:26 [INFO] number of open fds = 216
01:33:31 [INFO] number of open fds = 227
01:33:31 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:33:31 [INFO] number of open fds = 226
01:33:36 [INFO] number of open fds = 242
01:33:36 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:33:36 [INFO] number of open fds = 241
01:33:41 [INFO] number of open fds = 251
01:33:41 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:33:41 [INFO] number of open fds = 250
01:33:46 [INFO] number of open fds = 266
01:33:46 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:33:46 [INFO] number of open fds = 265
01:33:51 [INFO] number of open fds = 276
01:33:51 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:33:51 [INFO] number of open fds = 275
01:33:56 [INFO] number of open fds = 291
01:33:56 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:33:56 [INFO] number of open fds = 290
01:34:01 [INFO] number of open fds = 300
01:34:01 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:34:01 [INFO] number of open fds = 299
01:34:06 [INFO] number of open fds = 315
01:34:06 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:34:06 [INFO] number of open fds = 314
01:34:11 [INFO] number of open fds = 325
01:34:11 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:34:11 [INFO] number of open fds = 324
01:34:16 [INFO] number of open fds = 340
01:34:16 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:34:16 [INFO] number of open fds = 339
01:34:21 [INFO] number of open fds = 350
01:34:21 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:34:21 [INFO] number of open fds = 349
01:34:26 [INFO] number of open fds = 365
01:34:26 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:34:26 [INFO] number of open fds = 364
01:34:31 [INFO] number of open fds = 374
01:34:31 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:34:31 [INFO] number of open fds = 373
01:34:36 [INFO] number of open fds = 388
01:34:36 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:34:36 [INFO] number of open fds = 388
01:34:41 [INFO] number of open fds = 399
01:34:41 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:34:41 [INFO] number of open fds = 398
01:34:46 [INFO] number of open fds = 414
01:34:46 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:34:46 [INFO] number of open fds = 413
01:34:51 [INFO] number of open fds = 424
01:34:51 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:34:51 [INFO] number of open fds = 423
01:34:56 [INFO] number of open fds = 439
01:34:56 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:34:56 [INFO] number of open fds = 438
01:35:01 [INFO] number of open fds = 448
01:35:01 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:35:01 [INFO] number of open fds = 447
01:35:06 [INFO] number of open fds = 463
01:35:06 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:35:06 [INFO] number of open fds = 462
01:35:11 [INFO] number of open fds = 472
01:35:11 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:35:11 [INFO] number of open fds = 472
01:35:16 [INFO] number of open fds = 488
01:35:16 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:35:16 [INFO] number of open fds = 487
01:35:21 [INFO] number of open fds = 498
01:35:21 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:35:21 [INFO] number of open fds = 497
01:35:26 [INFO] number of open fds = 513
01:35:26 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:35:26 [INFO] number of open fds = 512
01:35:31 [INFO] number of open fds = 522
01:35:31 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:35:31 [INFO] number of open fds = 521
01:35:36 [INFO] number of open fds = 537
01:35:36 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:35:36 [INFO] number of open fds = 536
01:35:41 [INFO] number of open fds = 547
01:35:41 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:35:41 [INFO] number of open fds = 546
01:35:46 [INFO] number of open fds = 562
01:35:46 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:35:46 [INFO] number of open fds = 561
01:35:51 [INFO] number of open fds = 572
01:35:51 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:35:51 [INFO] number of open fds = 571
01:35:56 [INFO] number of open fds = 587
01:35:56 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:35:56 [INFO] number of open fds = 586
01:36:01 [INFO] number of open fds = 596
01:36:01 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:36:01 [INFO] number of open fds = 595
01:36:06 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:36:06 [INFO] number of open fds = 615
01:36:06 [INFO] number of open fds = 622
01:36:11 [INFO] number of open fds = 621
01:36:11 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:36:11 [INFO] number of open fds = 620
01:36:16 [INFO] number of open fds = 636
01:36:16 [INFO] Accepting connections on 127.0.0.1:8888 has been resumed
01:36:16 [INFO] number of open fds = 635
From what I see, backlog is getting drained faster than it should be. In strace
output one can see (this is the very beginning of Go connection generation):
$ sudo strace -Tt -f -p $(pidof actix-conn-limit) -e accept4,close
strace: Process 5159 attached with 3 threads
[pid 5405] 01:38:16 accept4(6, {sa_family=AF_INET, sin_port=htons(35126), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 19 <0.000042>
[pid 5405] 01:38:16 accept4(6, 0x7fe321cf4550, [128], SOCK_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable) <0.000019>
[pid 5404] 01:38:16 close(21) = 0 <0.000023>
[pid 5404] 01:38:16 close(20) = 0 <0.000011>
[pid 5404] 01:38:16 syscall_332(0, 0, 0, 0xfff, 0, 0x10) = -1 (errno 14) <0.000013>
[pid 5404] 01:38:16 syscall_332(0xffffffffffffff9c, 0x7fe31c006b00, 0, 0xfff, 0x7fe321eee620, 0) = 0 <0.000015>
[pid 5404] 01:38:16 close(20) = 0 <0.000010>
[pid 5405] 01:38:17 accept4(6, {sa_family=AF_INET, sin_port=htons(35128), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 20 <0.000018>
[pid 5405] 01:38:17 accept4(6, 0x7fe321cf4550, [128], SOCK_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable) <0.000017>
[pid 5404] 01:38:17 close(21) = 0 <0.000013>
[pid 5404] 01:38:17 syscall_332(0xffffffffffffff9c, 0x7fe31c006240, 0, 0xfff, 0x7fe321eee620, 0) = 0 <0.000025>
[pid 5404] 01:38:17 close(21) = 0 <0.000010>
[pid 5405] 01:38:17 accept4(6, {sa_family=AF_INET, sin_port=htons(35130), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 21 <0.000029>
[pid 5405] 01:38:17 accept4(6, 0x7fe321cf4550, [128], SOCK_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable) <0.000012>
[pid 5405] 01:38:17 accept4(6, {sa_family=AF_INET, sin_port=htons(35132), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 22 <0.000017>
[pid 5405] 01:38:17 accept4(6, 0x7fe321cf4550, [128], SOCK_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable) <0.000015>
[pid 5404] 01:38:21 close(20) = 0 <0.000056>
[pid 5404] 01:38:21 close(20) = 0 <0.000029>
[pid 5404] 01:38:21 syscall_332(0xffffffffffffff9c, 0x7fe31c007320, 0, 0xfff, 0x7fe321eee620, 0) = 0 <0.000019>
[pid 5404] 01:38:21 close(20) = 0 <0.000026>
[pid 5404] 01:38:21 close(19) = 0 <0.000033>
[pid 5404] 01:38:21 close(19) = 0 <0.000033>
[pid 5404] 01:38:21 syscall_332(0xffffffffffffff9c, 0x7fe31c02ae30, 0, 0xfff, 0x7fe321eee620, 0) = 0 <0.000018>
[pid 5404] 01:38:21 close(19) = 0 <0.000021>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35134), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 19 <0.000039>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35136), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 20 <0.000035>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35138), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 23 <0.000021>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35140), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 24 <0.000022>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35142), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 25 <0.000020>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35144), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 26 <0.000021>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35146), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 27 <0.000021>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35148), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 28 <0.000021>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35150), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 29 <0.000021>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35152), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 30 <0.000020>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35154), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 31 <0.000020>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35156), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 32 <0.000015>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35158), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 33 <0.000017>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35160), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 34 <0.000031>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35162), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 35 <0.000018>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35164), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 36 <0.000016>
[pid 5405] 01:38:21 accept4(6, {sa_family=AF_INET, sin_port=htons(35166), sin_addr=inet_addr("127.0.0.1")}, [128->16], SOCK_CLOEXEC) = 37 <0.000015>
[pid 5405] 01:38:21 accept4(6, 0x7fe321cf4550, [128], SOCK_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable) <0.000018>
In my mind max_connections
should never allow more than 2 consecutive accept4
without a close
between them.