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

Connection not closed correctly #439

Open
neowutran opened this Issue Aug 2, 2018 · 108 comments

Comments

Projects
None yet
8 participants
@neowutran

neowutran commented Aug 2, 2018

Connection are not closed correctly by default
What I means is: if you do a "netstat -ano" you will see connection list growing and growing.
Not all old connection get closed.

Tested with StaticFile handler ( HTTP2 or not ) on a website with ~20k+ daily users

With the default config -> Not closed correctly
With .keep_alive(None) -> Not closed correctly
With .keep_alive(server::KeepAlive::Timeout(5)) -> All connections are closed correctly

Initially detected in this ticket #426 but it was not the main issue

@neowutran

This comment has been minimized.

neowutran commented Aug 8, 2018

I was wrong with that
With .keep_alive(server::KeepAlive::Timeout(5)) -> All connections are closed correctly

I have some connection that are open for more than 1 day

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Aug 8, 2018

Master should fix this probables

@neowutran

This comment has been minimized.

neowutran commented Aug 9, 2018

Ok, trying

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Aug 11, 2018

do you still see opened connections?

@neowutran

This comment has been minimized.

neowutran commented Aug 11, 2018

Yes. connections are not closed correctly yet

Source code I used to test: https://git.neowutran.ovh:8080/neowutran/Website/commit/6e1a7ec41c4d521d42a8df81b01c469fe77b4a9c

Script I use to check if connection are closed correctly

[root@xxxxxx]# cat ./sockets_uptime.sh
#!/bin/bash
function suptime() {
    local addr=${1:?Specify the remote IPv4 address}
    local port=${2:?Specify the remote port number}
    local min_time=${3:?Specify the min uptime in seconds for socket}
    local min_time=${min_time%.*}
    # convert the provided address to hex format
    local hex_addr=$(python -c "import socket, struct; print(hex(struct.unpack('<L', socket.inet_aton('$addr'))[0])[2:10].upper().zfill(8))")
    local hex_port=$(python -c "print(hex($port)[2:].upper().zfill(4))")
    # get the PID of the owner process
    local pid=$(netstat -ntp 2>/dev/null | awk '$6 == "ESTABLISHED" && $5 == "'$addr:$port'"{sub("/.*", "", $7); print $7}')
    #local pid=$(netstat -ntp 2>/dev/null | awk '$5 == "'$addr:$port'"{sub("/.*", "", $7); print $7}')
    [ -z "$pid" ] && {
#           echo 'Address does not match' 2>&1;
            return 1;
    }
    # get the inode of the socket
    local inode=$(awk '$4 == "01" && $3 == "'$hex_addr:$hex_port'" {print $10}' /proc/net/tcp)
    [ -z "$inode" ] && { echo 'Cannot lookup the socket' 2>&1; return 1; }
    # query the inode status change time
    local timestamp=$(find /proc/$pid/fd -lname "socket:\[$inode\]" -printf %T@)
    [ -z "$timestamp" ] && { echo 'Cannot fetch the timestamp' 2>&1; return 1; }

    local diff=$(bc <<< "$(date +%s.%N) - $timestamp")
    # truncate to int
    local diff=${diff%.*}
    if (( $diff > $min_time )); then
        # compute the time difference
        LANG=C printf '%s (%.2fs ago)\n' "$(date -d @$timestamp)" $diff
        echo $addr:$port
    fi
}

min_time=${1:?Specify the min uptime in seconds for socket}
ports=${2:?Specify the ports list, like ':8083|:443'}
#ports=':8083|:443'
echo "min uptime in seconds for sockets: $min_time"
netstat -ano | grep -E $ports | sed -e "s/[[:space:]]\+/\t/g" | cut -f5 | while read line
do
        ip=$(echo "$line" | cut -d ':' -f1 )
        port=$(echo "$line" | cut -d ':' -f2)
        suptime $ip $port $min_time

done

(based on https://superuser.com/questions/565991/how-to-determine-the-socket-connection-up-time-on-linux )
usage ./sockets_uptime.sh 3600 ':443' 2> /dev/null 
Show socket connected to port 443 that where created more than 1 hour ago.

After ~2 hours, I have 23 sockets not closed correctly
But there is an interesting thing about them:
15 sockets where created exactly at 18:07:13
2 sockets where created exactly at 18:15:32
6 sockets where created exactly at 18:26:28
The process was started at 18:05:33

Some "burst" of sockets not closed.

The bad thing: I am unable to reproduce this issue without a heavy load ( port 443, the service is mainly used to download big files like this one #454 (comment) ).

Process is still running, will update the stats in few hours

@neowutran

This comment has been minimized.

neowutran commented Aug 12, 2018

Now I am at 32 sockets not closed correctly.
15 sockets where created exactly at 18:07:13
2 sockets where created exactly at 18:15:32
6 sockets where created exactly at 18:26:28
4 socket where created exactly at 18:55:45
The others socket where created at different time, but nothing really interesting with them.

Don't have any unclosed socket created between 22h and 06h ( not much traffic in these hours )
Process is still running.
I expect a small traffic spike today at around 17h/18h, so I think a lot of socket won't be closed at around 17h

@neowutran

This comment has been minimized.

neowutran commented Aug 13, 2018

Now: ~50 sockets not closed correctly
As expected, most of the new sockets not closed correctly have been created around 17/18h

More than 2 sockets unclosed where created exactly at:

  • 18:15:32
  • 18:26:28
  • 18:13:16
  • 18:07:13
  • 18:55:44
  • 06:20:20

So definitly Some "burst" of sockets not closed.

Killing the process

@neowutran

This comment has been minimized.

neowutran commented Aug 15, 2018

@fafhrd91
@DoumanAsh

Do you have an idea ?

I can easily reproduce this case on my server when it is heavily loaded.

Do you know a part of the code ( / external crate ) handling the sockets that could be sensitive to timestamp / race condition ?
I can add logs / trace where you want if you have an idea.

But quite a complexe issue

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Aug 15, 2018

I am a bit busy atm, I’ll get back to this bug this weekend

@Neopallium

This comment has been minimized.

Contributor

Neopallium commented Aug 26, 2018

@neowutran I might have fixed this. Try this pull-request #483

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Aug 26, 2018

@neowutran i merged pr, could you try master

@neowutran

This comment has been minimized.

neowutran commented Aug 28, 2018

Updated everything

Tested both with http1 only & http1/htt2
There are still unclosed sockets.
Last logs from the service with http1 only:

[root@xxxxxxxx ~]# ./sockets_uptime.sh 3600 443
min uptime in seconds for sockets: 3600
Mon Aug 27 12:31:08 CEST 2018 (101857.00s ago)
xxx.xxx.xxx.xxx:50289
Mon Aug 27 11:37:33 CEST 2018 (105073.00s ago)
xxx.xxx.xxx.xxx:55272
Mon Aug 27 11:23:44 CEST 2018 (105902.00s ago)
xxx.xxx.xxx.xxx:9257
Mon Aug 27 11:08:56 CEST 2018 (106790.00s ago)
xxx.xxx.xxx.xxx:53753
Mon Aug 27 12:31:08 CEST 2018 (101858.00s ago)
xxx.xxx.xxx.xxx:54859
Mon Aug 27 11:37:32 CEST 2018 (105075.00s ago)
xxx.xxx.xxx.xxx:6722
Mon Aug 27 11:37:30 CEST 2018 (105077.00s ago)
xxx.xxx.xxx.xxx:49868
Mon Aug 27 11:29:07 CEST 2018 (105580.00s ago)
xxx.xxx.xxx.xxx:8918
Mon Aug 27 11:37:30 CEST 2018 (105077.00s ago)
xxx.xxx.xxx.xxx:49867
Mon Aug 27 11:37:33 CEST 2018 (105075.00s ago)
xxx.xxx.xxx.xxx:53231
Mon Aug 27 11:23:43 CEST 2018 (105905.00s ago)
xxx.xxx.xxx.xxx:47600
Mon Aug 27 11:29:07 CEST 2018 (105581.00s ago)
xxx.xxx.xxx.xxx:8919
Mon Aug 27 11:37:33 CEST 2018 (105076.00s ago)
xxx.xxx.xxx.xxx:11313
Mon Aug 27 11:37:30 CEST 2018 (105079.00s ago)
xxx.xxx.xxx.xxx:55125
Mon Aug 27 11:37:30 CEST 2018 (105079.00s ago)
xxx.xxx.xxx.xxx:55894
Mon Aug 27 11:09:01 CEST 2018 (106789.00s ago)
xxx.xxx.xxx.xxx:9254
Mon Aug 27 11:08:56 CEST 2018 (106795.00s ago)
xxx.xxx.xxx.xxx:9424
Mon Aug 27 12:31:08 CEST 2018 (101863.00s ago)
xxx.xxx.xxx.xxx:5936
Mon Aug 27 11:37:30 CEST 2018 (105081.00s ago)
xxx.xxx.xxx.xxx:52727
Mon Aug 27 11:37:30 CEST 2018 (105081.00s ago)
xxx.xxx.xxx.xxx:25074
Mon Aug 27 11:37:30 CEST 2018 (105082.00s ago)
xxx.xxx.xxx.xxx:52718
Mon Aug 27 12:31:08 CEST 2018 (101864.00s ago)
xxx.xxx.xxx.xxx:11314
Mon Aug 27 12:31:08 CEST 2018 (101864.00s ago)
xxx.xxx.xxx.xxx:29972
Mon Aug 27 12:31:08 CEST 2018 (101864.00s ago)
xxx.xxx.xxx.xxx:37362
Mon Aug 27 12:31:08 CEST 2018 (101865.00s ago)
xxx.xxx.xxx.xxx:54365
Mon Aug 27 11:23:43 CEST 2018 (105910.00s ago)
xxx.xxx.xxx.xxx:60080

The service was launched on my port 443, I didn't used any stress tool on it
There is still this "burst" pattern, with many socket created at the exact same time and that didn't get closed

I am unable to reproduce this behavior on localhost. Will see if I can consistently reproduce that on a remote server with a http stress tool

@DoumanAsh

This comment has been minimized.

Contributor

DoumanAsh commented Aug 28, 2018

@neowutran is this with Os keep-alive or timeout?

@neowutran

This comment has been minimized.

neowutran commented Aug 28, 2018

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Aug 28, 2018

@neowutran could you test with keep alive timeout

@neowutran

This comment has been minimized.

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Aug 28, 2018

Looks good

@neowutran

This comment has been minimized.

neowutran commented Aug 29, 2018

Yup, same thing

[root@vps193339 ~]# ./sockets_uptime.sh 3600 443 2> /dev/null
min uptime in seconds for sockets: 3600
Tue Aug 28 19:44:57 CEST 2018 (76319.00s ago)
xxx.xxx.xxx.xxx:55605
Tue Aug 28 19:44:57 CEST 2018 (76320.00s ago)
xxx.xxx.xxx.xxx:49684
Tue Aug 28 19:44:57 CEST 2018 (76320.00s ago)
xxx.xxx.xxx.xxx:1379

Same condition:
The service was launched on my port 443, I didn't used any stress tool on it

@neowutran

This comment has been minimized.

neowutran commented Sep 8, 2018

another thing related: after a stress test, CPU consumption stay at 100% for a very long time

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Sep 8, 2018

Do you see not closed connections?

@neowutran

This comment has been minimized.

neowutran commented Sep 8, 2018

Only ~50

@Neopallium

This comment has been minimized.

Contributor

Neopallium commented Sep 8, 2018

@neowutran I have seen an issue with connections not being closed.

I have just setup a test environment (two computers on gigabit LAN) for stress testing. I can cause actix-web to have connections that are not closed (ESTABLISHED state on the server, gone on the client). I haven't seen this problem with localhost stress testing, even with 200,000 concurrent connections.

I have been able to cause it some times with:

wrk -c 4000 -d 10 -t 20 http://server:8080/

I happens more often with higher concurrent connection counts. Using 20 threads seems to help cause the problem, even though the client only has 2 cores + hyper-threading.

@Neopallium

This comment has been minimized.

Contributor

Neopallium commented Sep 8, 2018

The hung connections that I was seeing were caused by dropped RST/FIN packets. The kernel will never closing these connections, until a new RST packet is sent from the client. That might never happen.

@neowutran Do you still have keepalive enabled? That should have closed those connection if they were idle. Maybe use tcpdump to check if the connection is idle for longer then the keepalive timeout.

@fafhrd91 I think the default KeepAlive::Os is not a good default. Connections can hang around for a very long time if the RST/FIN packets are lost.

@Neopallium

This comment has been minimized.

Contributor

Neopallium commented Sep 8, 2018

@fafhrd91 Even with KeepAlive::Timeout(30) some connections are not closed.

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Sep 8, 2018

@Neopallium when you stop server does actix reports not closed connections?

@Neopallium

This comment has been minimized.

Contributor

Neopallium commented Sep 8, 2018

@fafhrd91 Yes. Each worker thread reported about 350 connections when actix-web was shutdown with Ctrl-C. actix-web = 0.7.6 release build.

The leaked connections doesn't always happen. High concurrent connection count (200,000) seems to be the easiest way to cause it.

I have been testing with:

wrk -c 200000 -d 60 -t 20 -s scripts/ports.lua http://server:8080/

scripts/ports.lua file changes the connecting port (8080 -> 8099) for each thread.

local next_port = nil
function setup(thread)
	local port = next_port or wrk.port or 80
	next_port = port + 1

	local addrs = wrk.lookup(wrk.host, port)
	thread.addr = addrs[1]
end

function init(args)
	print(("thread addr: %s"):format(wrk.thread.addr))
end

The server is just the hello-world example changed to listen on ports 8080-8099. This make it easier to do high concurrent connection testing with just one client computer.

I will do some more testing tomorrow, to see if I can narrow down the problem.

@Neopallium

This comment has been minimized.

Contributor

Neopallium commented Sep 15, 2018

@fafhrd91 It looks like the leaked connections are closed before sending a HTTP request and the RST/FIN packet is lost. The keep-alive timer isn't created until the connections protocol has been detected (http1/http2).

I think Actix-web should have a timeout for receiving the first request (nginx has a few timeouts like client_header_timeout, client_body_timeout). We can't rely on the OS always detecting a closed connection (unless TCP keep-alive is enabled).

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Sep 15, 2018

@Neopallium do you think actix process does not get HUP event from kernel?

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Sep 15, 2018

@Neopallium could test master again, i added slow request timer

@Neopallium

This comment has been minimized.

Contributor

Neopallium commented Sep 24, 2018

@neowutran still only leaked connections on port 443 and not 8083?

Also would it be possible to enable access logging on that port to narrow down what kind of requests are happening on the leaked connections?

I am traveling for the next two weeks. So I will not be able to help much with debugging.

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Sep 24, 2018

I think this is the same problem. We have to start slow request timer before ssl negotiation, which is not the case at the moment

@neowutran

This comment has been minimized.

neowutran commented Sep 27, 2018

Another memory leak, probably related to this issue
https://neowutran.ovh/upload_leak.log

Live traffic, mostly upload ( files upload / json upload )

@ghost

This comment has been minimized.

ghost commented Sep 30, 2018

I have some updates about connections not being closed correctly.

I made some simple protocol over tcp, via tokio + futures crates. That means I replaced actix-web and rolled my own (simple) protocol. I couldn't test with wrk, so I ran my own tests. There were just about 500 requests/second. I know my implementation is poorly coded. (Last time I ran wrk on my implementation with actix-web, it handled up to 20k requests/second.)

However the thing is, no matter how many tests I ran, there were absolutely no unclosed connections when the tests finished. I ran tests again, again and again, and again... There were no unclosed connections.

Then, I used that for production code. When time goes, they appear and go up (the unclosed connections).

I just can guess that there might be some bugs in tokio or futures crates.

@dnagir

This comment has been minimized.

dnagir commented Sep 30, 2018

Not sure if this is useful, but I think I have a similar issue. Repro in this repo https://github.com/dnagir/rust-memomry-leak

But as others pointed out - it might be reproducible with a much smaller example.

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Sep 30, 2018

@dnagir thats for test. i tried to test with system allocator, i dont see leak with stress-alpine. Could you check?

#![feature(alloc_system, allocator_api)]
extern crate alloc_system;
use alloc_system::System;
#[global_allocator]
static A: System = System;
@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Sep 30, 2018

@neowutran could you try master but with system allocator?

@neowutran

This comment has been minimized.

neowutran commented Oct 1, 2018

@fafhrd91 already what I am using, unless you mean that you need the "allocator_api"
@Neopallium For the socket not correctly closed that I have, nothing have been registered by the actix middleware. So it never reached it.
Maybe I can activate logs on the firewall level to see what kind of tcp packet is causing the issue

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Oct 1, 2018

@neowutran yes, "allocator_api". master contains extra timer for ssl handshake, similar to slow request timeout in 0.7.8, I merged it last Friday.

@neowutran

This comment has been minimized.

neowutran commented Oct 2, 2018

@fafhrd91
Update this morning,
sadly, a lot of new leaks ( from 0.1% of server ram to 12% in ~5 hours)
and at least 1 new bug -> files download cannot complete, it goes to 99% then get stuck indefinitly

https://neowutran.ovh:8080/valgrind_debug5.err

trying again with lastest changes on master

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Oct 2, 2018

@neowutran could you update from master again.

@neowutran

This comment has been minimized.

neowutran commented Oct 8, 2018

@fafhrd91
It leak way less memory, and the download bug is fixed
However, after few days with live traffic, I have few hundred unclosed connections - 200+ - ( and memory still leak, but slower )

...
Thu Oct  4 17:57:14 CEST 2018 (303206.00s ago)
XXX.XXX.XX.XXX:41003
Thu Oct  4 17:47:21 CEST 2018 (303800.00s ago)
XXX.XXX.XX.XXX:53984
Thu Oct  4 17:47:21 CEST 2018 (303800.00s ago)
XXX.XXX.XX.XXX:59036
Thu Oct  4 17:47:21 CEST 2018 (303800.00s ago)
XXX.XXX.XX.XXX:57494
Thu Oct  4 17:47:21 CEST 2018 (303801.00s ago)
XXX.XXX.XX.XXX:3255
Thu Oct  4 17:47:21 CEST 2018 (303801.00s ago)
XXX.XXX.XX.XXX:63601
Thu Oct  4 17:47:21 CEST 2018 (303801.00s ago)
XXX.XXX.XX.XXX:57461
Thu Oct  4 17:47:21 CEST 2018 (303801.00s ago)
XXX.XXX.XX.XXX:57460
Thu Oct  4 17:47:21 CEST 2018 (303801.00s ago)
XXX.XXX.XX.XXX:51997
Thu Oct  4 17:50:01 CEST 2018 (303641.00s ago)
XXX.XXX.XX.XXX:60789
Thu Oct  4 17:47:21 CEST 2018 (303802.00s ago)
XXX.XXX.XX.XXX:51863
Thu Oct  4 17:47:21 CEST 2018 (303804.00s ago)
XXX.XXX.XX.XXX:1488
Thu Oct  4 17:47:21 CEST 2018 (303804.00s ago)
XXX.XXX.XX.XXX:58210
Thu Oct  4 17:47:21 CEST 2018 (303804.00s ago)
XXX.XXX.XX.XXX:24316
Thu Oct  4 17:47:21 CEST 2018 (303804.00s ago)
XXX.XXX.XX.XXX:53985
Thu Oct  4 17:47:21 CEST 2018 (303805.00s ago)
XXX.XXX.XX.XXX:49394
Thu Oct  4 17:47:21 CEST 2018 (303805.00s ago)
XXX.XXX.XX.XXX:61586
Thu Oct  4 17:47:21 CEST 2018 (303805.00s ago)
XXX.XXX.XX.XXX:1027
Thu Oct  4 17:47:21 CEST 2018 (303805.00s ago)
XXX.XXX.XX.XXX:2530
Thu Oct  4 17:47:21 CEST 2018 (303806.00s ago)
XXX.XXX.XX.XXX:9384
Thu Oct  4 17:47:21 CEST 2018 (303806.00s ago)
XXX.XXX.XX.XXX:5169
Thu Oct  4 17:47:21 CEST 2018 (303806.00s ago)
XXX.XXX.XX.XXX:49586
Thu Oct  4 17:47:21 CEST 2018 (303807.00s ago)
XXX.XXX.XX.XXX:56157
Thu Oct  4 17:47:21 CEST 2018 (303807.00s ago)
XXX.XXX.XX.XXX:50240
Thu Oct  4 17:57:10 CEST 2018 (303218.00s ago)
XXX.XXX.XX.XXX:59708
Thu Oct  4 17:47:21 CEST 2018 (303808.00s ago)
XXX.XXX.XX.XXX:26615
Thu Oct  4 17:47:21 CEST 2018 (303808.00s ago)
XXX.XXX.XX.XXX:50059

October 4, 17h match with a very high number of users connected to the server. The 200+ unclosed connections are at 17h47 +- few minutes
Same pattern: Multiple unclosed connection at the exact same time

@neowutran

This comment has been minimized.

neowutran commented Oct 9, 2018

Reached ~500 unclosed connection with live traffic in ~5 days.

some log retrieved with valgrind:
https://neowutran.ovh/valgrind_debug7.err

I needed to do a kill -9 on the process, it was completly stuck

~~ no idea how to help testing this issue

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Oct 9, 2018

try latest master

@neowutran

This comment has been minimized.

neowutran commented Oct 13, 2018

Tried latest master, same issue
With live traffic I reached around 300 unclosed connections in 2 days, same "burst" pattern ( a lot of unclosed connection where created at the exact same time )
Valgrind output: https://neowutran.ovh/valgrind_debug8.err

@jcoleman-techempower

This comment has been minimized.

jcoleman-techempower commented Oct 25, 2018

Using a very, very basic implementation with the RUST_LOG environment variable set to debug on the latest version of Actix throws this error on every request, even on a simple plaintext route.

@legokichi

This comment has been minimized.

legokichi commented Oct 31, 2018

actix_web::server::KeepAlive::Timeout(5) does not send TCP FIN in 0.7.13

code

extern crate actix_web;
extern crate env_logger;
extern crate futures;
#[macro_use]
extern crate log;
extern crate failure;
extern crate tokio_timer;
use actix_web::middleware::{Logger};
use futures::prelude::*;
use actix_web::http::{StatusCode, Method};
use actix_web::{HttpRequest, HttpResponse};
use failure::Error;

fn main(){
    ::env_logger::init();

    let srv = ::actix_web::server::new(move ||{
        ::actix_web::App::new()
            .middleware(Logger::default())
            .resource("/", |r|{ r.method(Method::GET).with_async(get_index); })
    })
        .keep_alive(::actix_web::server::KeepAlive::Timeout(5)) // change here
        .bind("0.0.0.0:8081")
        .unwrap();
    srv.run();
    
}

/// GET /
pub fn get_index(_: HttpRequest) -> impl Future<Item=HttpResponse, Error=Error> {
    ::tokio_timer::sleep(::std::time::Duration::from_secs(0)).map(|()|{
        HttpResponse::Ok()
            .header("content-type", "text/plain; charset=utf-8")
            .body("🐲")
    }).map_err(Into::into)
}

telnet results, tcpdumps and trace logs

actix_web::server::KeepAlive::Timeout(5)

$ telnet localhost 8081
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
GET / HTTP/1.1

HTTP/1.1 200 OK
content-length: 4
content-type: text/plain; charset=utf-8
date: Wed, 31 Oct 2018 12:50:47 GMT

🐲GET / HTTP/1.1
Connection closed by foreign host.
TRACE 2018-10-31T12:50:30Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:50:30Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:50:30Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:50:30Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:50:30Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:50:30Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:50:30Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:50:30Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
 INFO 2018-10-31T12:50:47Z: actix_web::middleware::logger: 127.0.0.1:47654 "GET / HTTP/1.1" 200 4 "-" "-" 0.002296
TRACE 2018-10-31T12:50:58Z: actix_web::server::h1: Keep-alive timeout, close connection
$ sudo tcpdump -vvv -s 0 -nX -i lo -r lo-actix-keepalive-timeout-5 port 8081
reading from file lo-actix-keepalive-timeout-5, link-type EN10MB (Ethernet)
21:50:46.369544 IP (tos 0x10, ttl 64, id 35464, offset 0, flags [DF], proto TCP (6), length 60)
    127.0.0.1.47654 > 127.0.0.1.8081: Flags [S], cksum 0xfe30 (incorrect -> 0x4601), seq 3217823845, win 43690, options [mss 65495,sackOK,TS val 726696436 ecr 0,nop,wscale 7], length 0
	0x0000:  4510 003c 8a88 4000 4006 b221 7f00 0001  E..<..@.@..!....
	0x0010:  7f00 0001 ba26 1f91 bfcc 1865 0000 0000  .....&.....e....
	0x0020:  a002 aaaa fe30 0000 0204 ffd7 0402 080a  .....0..........
	0x0030:  2b50 81f4 0000 0000 0103 0307            +P..........
21:50:46.369576 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6), length 60)
    127.0.0.1.8081 > 127.0.0.1.47654: Flags [S.], cksum 0xfe30 (incorrect -> 0xb220), seq 1341560468, ack 3217823846, win 43690, options [mss 65495,sackOK,TS val 726696436 ecr 726696436,nop,wscale 7], length 0
	0x0000:  4500 003c 0000 4000 4006 3cba 7f00 0001  E..<..@.@.<.....
	0x0010:  7f00 0001 1f91 ba26 4ff6 9694 bfcc 1866  .......&O......f
	0x0020:  a012 aaaa fe30 0000 0204 ffd7 0402 080a  .....0..........
	0x0030:  2b50 81f4 2b50 81f4 0103 0307            +P..+P......
21:50:46.369606 IP (tos 0x10, ttl 64, id 35465, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.47654 > 127.0.0.1.8081: Flags [.], cksum 0xfe28 (incorrect -> 0x8465), seq 1, ack 1, win 342, options [nop,nop,TS val 726696436 ecr 726696436], length 0
	0x0000:  4510 0034 8a89 4000 4006 b228 7f00 0001  E..4..@.@..(....
	0x0010:  7f00 0001 ba26 1f91 bfcc 1866 4ff6 9695  .....&.....fO...
	0x0020:  8010 0156 fe28 0000 0101 080a 2b50 81f4  ...V.(......+P..
	0x0030:  2b50 81f4                                +P..
21:50:47.156359 IP (tos 0x10, ttl 64, id 35466, offset 0, flags [DF], proto TCP (6), length 68)
    127.0.0.1.47654 > 127.0.0.1.8081: Flags [P.], cksum 0xfe38 (incorrect -> 0xafa3), seq 1:17, ack 1, win 342, options [nop,nop,TS val 726697223 ecr 726696436], length 16
	0x0000:  4510 0044 8a8a 4000 4006 b217 7f00 0001  E..D..@.@.......
	0x0010:  7f00 0001 ba26 1f91 bfcc 1866 4ff6 9695  .....&.....fO...
	0x0020:  8018 0156 fe38 0000 0101 080a 2b50 8507  ...V.8......+P..
	0x0030:  2b50 81f4 4745 5420 2f20 4854 5450 2f31  +P..GET./.HTTP/1
	0x0040:  2e31 0d0a                                .1..
21:50:47.156414 IP (tos 0x0, ttl 64, id 1144, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47654: Flags [.], cksum 0xfe28 (incorrect -> 0x7e2f), seq 1, ack 17, win 342, options [nop,nop,TS val 726697223 ecr 726697223], length 0
	0x0000:  4500 0034 0478 4000 4006 384a 7f00 0001  E..4.x@.@.8J....
	0x0010:  7f00 0001 1f91 ba26 4ff6 9695 bfcc 1876  .......&O......v
	0x0020:  8010 0156 fe28 0000 0101 080a 2b50 8507  ...V.(......+P..
	0x0030:  2b50 8507                                +P..
21:50:47.951633 IP (tos 0x10, ttl 64, id 35467, offset 0, flags [DF], proto TCP (6), length 54)
    127.0.0.1.47654 > 127.0.0.1.8081: Flags [P.], cksum 0xfe2a (incorrect -> 0x6e00), seq 17:19, ack 1, win 342, options [nop,nop,TS val 726698018 ecr 726697223], length 2
	0x0000:  4510 0036 8a8b 4000 4006 b224 7f00 0001  E..6..@.@..$....
	0x0010:  7f00 0001 ba26 1f91 bfcc 1876 4ff6 9695  .....&.....vO...
	0x0020:  8018 0156 fe2a 0000 0101 080a 2b50 8822  ...V.*......+P."
	0x0030:  2b50 8507 0d0a                           +P....
21:50:47.951675 IP (tos 0x0, ttl 64, id 1145, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47654: Flags [.], cksum 0xfe28 (incorrect -> 0x77f7), seq 1, ack 19, win 342, options [nop,nop,TS val 726698018 ecr 726698018], length 0
	0x0000:  4500 0034 0479 4000 4006 3849 7f00 0001  E..4.y@.@.8I....
	0x0010:  7f00 0001 1f91 ba26 4ff6 9695 bfcc 1878  .......&O......x
	0x0020:  8010 0156 fe28 0000 0101 080a 2b50 8822  ...V.(......+P."
	0x0030:  2b50 8822                                +P."
21:50:47.954831 IP (tos 0x0, ttl 64, id 1146, offset 0, flags [DF], proto TCP (6), length 172)
    127.0.0.1.8081 > 127.0.0.1.47654: Flags [P.], cksum 0xfea0 (incorrect -> 0x8214), seq 1:121, ack 19, win 342, options [nop,nop,TS val 726698021 ecr 726698018], length 120
	0x0000:  4500 00ac 047a 4000 4006 37d0 7f00 0001  E....z@.@.7.....
	0x0010:  7f00 0001 1f91 ba26 4ff6 9695 bfcc 1878  .......&O......x
	0x0020:  8018 0156 fea0 0000 0101 080a 2b50 8825  ...V........+P.%
	0x0030:  2b50 8822 4854 5450 2f31 2e31 2032 3030  +P."HTTP/1.1.200
	0x0040:  204f 4b0d 0a63 6f6e 7465 6e74 2d6c 656e  .OK..content-len
	0x0050:  6774 683a 2034 0d0a 636f 6e74 656e 742d  gth:.4..content-
	0x0060:  7479 7065 3a20 7465 7874 2f70 6c61 696e  type:.text/plain
	0x0070:  3b20 6368 6172 7365 743d 7574 662d 380d  ;.charset=utf-8.
	0x0080:  0a64 6174 653a 2057 6564 2c20 3331 204f  .date:.Wed,.31.O
	0x0090:  6374 2032 3031 3820 3132 3a35 303a 3437  ct.2018.12:50:47
	0x00a0:  2047 4d54 0d0a 0d0a f09f 90b2            .GMT........
21:50:47.954858 IP (tos 0x10, ttl 64, id 35468, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.47654 > 127.0.0.1.8081: Flags [.], cksum 0xfe28 (incorrect -> 0x7779), seq 19, ack 121, win 342, options [nop,nop,TS val 726698021 ecr 726698021], length 0
	0x0000:  4510 0034 8a8c 4000 4006 b225 7f00 0001  E..4..@.@..%....
	0x0010:  7f00 0001 ba26 1f91 bfcc 1878 4ff6 970d  .....&.....xO...
	0x0020:  8010 0156 fe28 0000 0101 080a 2b50 8825  ...V.(......+P.%
	0x0030:  2b50 8825                                +P.%
21:50:58.624055 IP (tos 0x10, ttl 64, id 35469, offset 0, flags [DF], proto TCP (6), length 68)
    127.0.0.1.47654 > 127.0.0.1.8081: Flags [P.], cksum 0xfe38 (incorrect -> 0x7c1d), seq 19:35, ack 121, win 342, options [nop,nop,TS val 726708690 ecr 726698021], length 16
	0x0000:  4510 0044 8a8d 4000 4006 b214 7f00 0001  E..D..@.@.......
	0x0010:  7f00 0001 ba26 1f91 bfcc 1878 4ff6 970d  .....&.....xO...
	0x0020:  8018 0156 fe38 0000 0101 080a 2b50 b1d2  ...V.8......+P..
	0x0030:  2b50 8825 4745 5420 2f20 4854 5450 2f31  +P.%GET./.HTTP/1
	0x0040:  2e31 0d0a                                .1..
21:50:58.624692 IP (tos 0x0, ttl 64, id 1147, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47654: Flags [R.], cksum 0xfe28 (incorrect -> 0x240a), seq 121, ack 35, win 342, options [nop,nop,TS val 726708691 ecr 726708690], length 0
	0x0000:  4500 0034 047b 4000 4006 3847 7f00 0001  E..4.{@.@.8G....
	0x0010:  7f00 0001 1f91 ba26 4ff6 970d bfcc 1888  .......&O.......
	0x0020:  8014 0156 fe28 0000 0101 080a 2b50 b1d3  ...V.(......+P..
	0x0030:  2b50 b1d2                                +P..

actix_web::server::KeepAlive::Os

$ telnet localhost 8081
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
GET / HTTP/1.1

HTTP/1.1 200 OK
content-length: 4
content-type: text/plain; charset=utf-8
date: Wed, 31 Oct 2018 12:51:38 GMT

🐲Connection closed by foreign host.
TRACE 2018-10-31T12:51:34Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:51:34Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:51:34Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:51:34Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:51:34Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:51:34Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:51:34Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:51:34Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
 INFO 2018-10-31T12:51:38Z: actix_web::middleware::logger: 127.0.0.1:47666 "GET / HTTP/1.1" 200 4 "-" "-" 0.002420
TRACE 2018-10-31T12:51:41Z: actix_web::server::h1: Keep-alive timeout, close connection
$ sudo tcpdump -vvv -s 0 -nX -i lo -r lo-actix-keepalive-os port 8081     
reading from file lo-actix-keepalive-os, link-type EN10MB (Ethernet)
21:51:36.052822 IP (tos 0x10, ttl 64, id 46588, offset 0, flags [DF], proto TCP (6), length 60)
    127.0.0.1.47666 > 127.0.0.1.8081: Flags [S], cksum 0xfe30 (incorrect -> 0x88c7), seq 1555920526, win 43690, options [mss 65495,sackOK,TS val 726746119 ecr 0,nop,wscale 7], length 0
	0x0000:  4510 003c b5fc 4000 4006 86ad 7f00 0001  E..<..@.@.......
	0x0010:  7f00 0001 ba32 1f91 5cbd 768e 0000 0000  .....2..\.v.....
	0x0020:  a002 aaaa fe30 0000 0204 ffd7 0402 080a  .....0..........
	0x0030:  2b51 4407 0000 0000 0103 0307            +QD.........
21:51:36.052854 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6), length 60)
    127.0.0.1.8081 > 127.0.0.1.47666: Flags [S.], cksum 0xfe30 (incorrect -> 0x4f6b), seq 978751388, ack 1555920527, win 43690, options [mss 65495,sackOK,TS val 726746119 ecr 726746119,nop,wscale 7], length 0
	0x0000:  4500 003c 0000 4000 4006 3cba 7f00 0001  E..<..@.@.<.....
	0x0010:  7f00 0001 1f91 ba32 3a56 8f9c 5cbd 768f  .......2:V..\.v.
	0x0020:  a012 aaaa fe30 0000 0204 ffd7 0402 080a  .....0..........
	0x0030:  2b51 4407 2b51 4407 0103 0307            +QD.+QD.....
21:51:36.052883 IP (tos 0x10, ttl 64, id 46589, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.47666 > 127.0.0.1.8081: Flags [.], cksum 0xfe28 (incorrect -> 0x21b0), seq 1, ack 1, win 342, options [nop,nop,TS val 726746119 ecr 726746119], length 0
	0x0000:  4510 0034 b5fd 4000 4006 86b4 7f00 0001  E..4..@.@.......
	0x0010:  7f00 0001 ba32 1f91 5cbd 768f 3a56 8f9d  .....2..\.v.:V..
	0x0020:  8010 0156 fe28 0000 0101 080a 2b51 4407  ...V.(......+QD.
	0x0030:  2b51 4407                                +QD.
21:51:36.719542 IP (tos 0x10, ttl 64, id 46590, offset 0, flags [DF], proto TCP (6), length 68)
    127.0.0.1.47666 > 127.0.0.1.8081: Flags [P.], cksum 0xfe38 (incorrect -> 0x4d66), seq 1:17, ack 1, win 342, options [nop,nop,TS val 726746786 ecr 726746119], length 16
	0x0000:  4510 0044 b5fe 4000 4006 86a3 7f00 0001  E..D..@.@.......
	0x0010:  7f00 0001 ba32 1f91 5cbd 768f 3a56 8f9d  .....2..\.v.:V..
	0x0020:  8018 0156 fe38 0000 0101 080a 2b51 46a2  ...V.8......+QF.
	0x0030:  2b51 4407 4745 5420 2f20 4854 5450 2f31  +QD.GET./.HTTP/1
	0x0040:  2e31 0d0a                                .1..
21:51:36.719593 IP (tos 0x0, ttl 64, id 19695, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47666: Flags [.], cksum 0xfe28 (incorrect -> 0x1c6a), seq 1, ack 17, win 342, options [nop,nop,TS val 726746786 ecr 726746786], length 0
	0x0000:  4500 0034 4cef 4000 4006 efd2 7f00 0001  E..4L.@.@.......
	0x0010:  7f00 0001 1f91 ba32 3a56 8f9d 5cbd 769f  .......2:V..\.v.
	0x0020:  8010 0156 fe28 0000 0101 080a 2b51 46a2  ...V.(......+QF.
	0x0030:  2b51 46a2                                +QF.
21:51:38.218838 IP (tos 0x10, ttl 64, id 46591, offset 0, flags [DF], proto TCP (6), length 54)
    127.0.0.1.47666 > 127.0.0.1.8081: Flags [P.], cksum 0xfe2a (incorrect -> 0x097b), seq 17:19, ack 1, win 342, options [nop,nop,TS val 726748285 ecr 726746786], length 2
	0x0000:  4510 0036 b5ff 4000 4006 86b0 7f00 0001  E..6..@.@.......
	0x0010:  7f00 0001 ba32 1f91 5cbd 769f 3a56 8f9d  .....2..\.v.:V..
	0x0020:  8018 0156 fe2a 0000 0101 080a 2b51 4c7d  ...V.*......+QL}
	0x0030:  2b51 46a2 0d0a                           +QF...
21:51:38.218870 IP (tos 0x0, ttl 64, id 19696, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47666: Flags [.], cksum 0xfe28 (incorrect -> 0x10b2), seq 1, ack 19, win 342, options [nop,nop,TS val 726748285 ecr 726748285], length 0
	0x0000:  4500 0034 4cf0 4000 4006 efd1 7f00 0001  E..4L.@.@.......
	0x0010:  7f00 0001 1f91 ba32 3a56 8f9d 5cbd 76a1  .......2:V..\.v.
	0x0020:  8010 0156 fe28 0000 0101 080a 2b51 4c7d  ...V.(......+QL}
	0x0030:  2b51 4c7d                                +QL}
21:51:38.222134 IP (tos 0x0, ttl 64, id 19697, offset 0, flags [DF], proto TCP (6), length 172)
    127.0.0.1.8081 > 127.0.0.1.47666: Flags [P.], cksum 0xfea0 (incorrect -> 0x1ace), seq 1:121, ack 19, win 342, options [nop,nop,TS val 726748288 ecr 726748285], length 120
	0x0000:  4500 00ac 4cf1 4000 4006 ef58 7f00 0001  E...L.@.@..X....
	0x0010:  7f00 0001 1f91 ba32 3a56 8f9d 5cbd 76a1  .......2:V..\.v.
	0x0020:  8018 0156 fea0 0000 0101 080a 2b51 4c80  ...V........+QL.
	0x0030:  2b51 4c7d 4854 5450 2f31 2e31 2032 3030  +QL}HTTP/1.1.200
	0x0040:  204f 4b0d 0a63 6f6e 7465 6e74 2d6c 656e  .OK..content-len
	0x0050:  6774 683a 2034 0d0a 636f 6e74 656e 742d  gth:.4..content-
	0x0060:  7479 7065 3a20 7465 7874 2f70 6c61 696e  type:.text/plain
	0x0070:  3b20 6368 6172 7365 743d 7574 662d 380d  ;.charset=utf-8.
	0x0080:  0a64 6174 653a 2057 6564 2c20 3331 204f  .date:.Wed,.31.O
	0x0090:  6374 2032 3031 3820 3132 3a35 313a 3338  ct.2018.12:51:38
	0x00a0:  2047 4d54 0d0a 0d0a f09f 90b2            .GMT........
21:51:38.222169 IP (tos 0x10, ttl 64, id 46592, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.47666 > 127.0.0.1.8081: Flags [.], cksum 0xfe28 (incorrect -> 0x1034), seq 19, ack 121, win 342, options [nop,nop,TS val 726748288 ecr 726748288], length 0
	0x0000:  4510 0034 b600 4000 4006 86b1 7f00 0001  E..4..@.@.......
	0x0010:  7f00 0001 ba32 1f91 5cbd 76a1 3a56 9015  .....2..\.v.:V..
	0x0020:  8010 0156 fe28 0000 0101 080a 2b51 4c80  ...V.(......+QL.
	0x0030:  2b51 4c80                                +QL.
21:51:41.055305 IP (tos 0x0, ttl 64, id 19698, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47666: Flags [F.], cksum 0xfe28 (incorrect -> 0x0521), seq 121, ack 19, win 342, options [nop,nop,TS val 726751122 ecr 726748288], length 0
	0x0000:  4500 0034 4cf2 4000 4006 efcf 7f00 0001  E..4L.@.@.......
	0x0010:  7f00 0001 1f91 ba32 3a56 9015 5cbd 76a1  .......2:V..\.v.
	0x0020:  8011 0156 fe28 0000 0101 080a 2b51 5792  ...V.(......+QW.
	0x0030:  2b51 4c80                                +QL.
21:51:41.055549 IP (tos 0x10, ttl 64, id 46593, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.47666 > 127.0.0.1.8081: Flags [F.], cksum 0xfe28 (incorrect -> 0xfa0d), seq 19, ack 122, win 342, options [nop,nop,TS val 726751122 ecr 726751122], length 0
	0x0000:  4510 0034 b601 4000 4006 86b0 7f00 0001  E..4..@.@.......
	0x0010:  7f00 0001 ba32 1f91 5cbd 76a1 3a56 9016  .....2..\.v.:V..
	0x0020:  8011 0156 fe28 0000 0101 080a 2b51 5792  ...V.(......+QW.
	0x0030:  2b51 5792                                +QW.
21:51:41.055601 IP (tos 0x0, ttl 64, id 19699, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47666: Flags [.], cksum 0xfe28 (incorrect -> 0xfa0d), seq 122, ack 20, win 342, options [nop,nop,TS val 726751122 ecr 726751122], length 0
	0x0000:  4500 0034 4cf3 4000 4006 efce 7f00 0001  E..4L.@.@.......
	0x0010:  7f00 0001 1f91 ba32 3a56 9016 5cbd 76a2  .......2:V..\.v.
	0x0020:  8010 0156 fe28 0000 0101 080a 2b51 5792  ...V.(......+QW.
	0x0030:  2b51 5792                                +QW.

actix_web::server::KeepAlive::Disabled (without Conection: close)

$ telnet localhost 8081
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
GET / HTTP/1.1

HTTP/1.1 200 OK
content-length: 4
content-type: text/plain; charset=utf-8
date: Wed, 31 Oct 2018 12:52:45 GMT

🐲Connection closed by foreign host.
TRACE 2018-10-31T12:52:40Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:52:40Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:52:40Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:52:40Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:52:40Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:52:40Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:52:40Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:52:40Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
 INFO 2018-10-31T12:52:45Z: actix_web::middleware::logger: 127.0.0.1:47682 "GET / HTTP/1.1" 200 4 "-" "-" 0.001000
$ sudo tcpdump -vvv -s 0 -nX -i lo -r lo-actix-keepalive-disabled port 8081
reading from file lo-actix-keepalive-disabled, link-type EN10MB (Ethernet)
21:52:43.979630 IP (tos 0x10, ttl 64, id 16549, offset 0, flags [DF], proto TCP (6), length 60)
    127.0.0.1.47682 > 127.0.0.1.8081: Flags [S], cksum 0xfe30 (incorrect -> 0xe2ba), seq 713246061, win 43690, options [mss 65495,sackOK,TS val 726814046 ecr 0,nop,wscale 7], length 0
	0x0000:  4510 003c 40a5 4000 4006 fc04 7f00 0001  E..<@.@.@.......
	0x0010:  7f00 0001 ba42 1f91 2a83 456d 0000 0000  .....B..*.Em....
	0x0020:  a002 aaaa fe30 0000 0204 ffd7 0402 080a  .....0..........
	0x0030:  2b52 4d5e 0000 0000 0103 0307            +RM^........
21:52:43.979671 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6), length 60)
    127.0.0.1.8081 > 127.0.0.1.47682: Flags [S.], cksum 0xfe30 (incorrect -> 0xf16a), seq 3296441362, ack 713246062, win 43690, options [mss 65495,sackOK,TS val 726814046 ecr 726814046,nop,wscale 7], length 0
	0x0000:  4500 003c 0000 4000 4006 3cba 7f00 0001  E..<..@.@.<.....
	0x0010:  7f00 0001 1f91 ba42 c47b b412 2a83 456e  .......B.{..*.En
	0x0020:  a012 aaaa fe30 0000 0204 ffd7 0402 080a  .....0..........
	0x0030:  2b52 4d5e 2b52 4d5e 0103 0307            +RM^+RM^....
21:52:43.979701 IP (tos 0x10, ttl 64, id 16550, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.47682 > 127.0.0.1.8081: Flags [.], cksum 0xfe28 (incorrect -> 0xc3af), seq 1, ack 1, win 342, options [nop,nop,TS val 726814046 ecr 726814046], length 0
	0x0000:  4510 0034 40a6 4000 4006 fc0b 7f00 0001  E..4@.@.@.......
	0x0010:  7f00 0001 ba42 1f91 2a83 456e c47b b413  .....B..*.En.{..
	0x0020:  8010 0156 fe28 0000 0101 080a 2b52 4d5e  ...V.(......+RM^
	0x0030:  2b52 4d5e                                +RM^
21:52:44.841175 IP (tos 0x10, ttl 64, id 16551, offset 0, flags [DF], proto TCP (6), length 68)
    127.0.0.1.47682 > 127.0.0.1.8081: Flags [P.], cksum 0xfe38 (incorrect -> 0xeea3), seq 1:17, ack 1, win 342, options [nop,nop,TS val 726814907 ecr 726814046], length 16
	0x0000:  4510 0044 40a7 4000 4006 fbfa 7f00 0001  E..D@.@.@.......
	0x0010:  7f00 0001 ba42 1f91 2a83 456e c47b b413  .....B..*.En.{..
	0x0020:  8018 0156 fe38 0000 0101 080a 2b52 50bb  ...V.8......+RP.
	0x0030:  2b52 4d5e 4745 5420 2f20 4854 5450 2f31  +RM^GET./.HTTP/1
	0x0040:  2e31 0d0a                                .1..
21:52:44.841216 IP (tos 0x0, ttl 64, id 45531, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47682: Flags [.], cksum 0xfe28 (incorrect -> 0xbce5), seq 1, ack 17, win 342, options [nop,nop,TS val 726814907 ecr 726814907], length 0
	0x0000:  4500 0034 b1db 4000 4006 8ae6 7f00 0001  E..4..@.@.......
	0x0010:  7f00 0001 1f91 ba42 c47b b413 2a83 457e  .......B.{..*.E~
	0x0020:  8010 0156 fe28 0000 0101 080a 2b52 50bb  ...V.(......+RP.
	0x0030:  2b52 50bb                                +RP.
21:52:45.537356 IP (tos 0x10, ttl 64, id 16552, offset 0, flags [DF], proto TCP (6), length 54)
    127.0.0.1.47682 > 127.0.0.1.8081: Flags [P.], cksum 0xfe2a (incorrect -> 0xad18), seq 17:19, ack 1, win 342, options [nop,nop,TS val 726815604 ecr 726814907], length 2
	0x0000:  4510 0036 40a8 4000 4006 fc07 7f00 0001  E..6@.@.@.......
	0x0010:  7f00 0001 ba42 1f91 2a83 457e c47b b413  .....B..*.E~.{..
	0x0020:  8018 0156 fe2a 0000 0101 080a 2b52 5374  ...V.*......+RSt
	0x0030:  2b52 50bb 0d0a                           +RP...
21:52:45.537396 IP (tos 0x0, ttl 64, id 45532, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47682: Flags [.], cksum 0xfe28 (incorrect -> 0xb771), seq 1, ack 19, win 342, options [nop,nop,TS val 726815604 ecr 726815604], length 0
	0x0000:  4500 0034 b1dc 4000 4006 8ae5 7f00 0001  E..4..@.@.......
	0x0010:  7f00 0001 1f91 ba42 c47b b413 2a83 4580  .......B.{..*.E.
	0x0020:  8010 0156 fe28 0000 0101 080a 2b52 5374  ...V.(......+RSt
	0x0030:  2b52 5374                                +RSt
21:52:45.539239 IP (tos 0x0, ttl 64, id 45533, offset 0, flags [DF], proto TCP (6), length 172)
    127.0.0.1.8081 > 127.0.0.1.47682: Flags [P.], cksum 0xfea0 (incorrect -> 0xbf92), seq 1:121, ack 19, win 342, options [nop,nop,TS val 726815605 ecr 726815604], length 120
	0x0000:  4500 00ac b1dd 4000 4006 8a6c 7f00 0001  E.....@.@..l....
	0x0010:  7f00 0001 1f91 ba42 c47b b413 2a83 4580  .......B.{..*.E.
	0x0020:  8018 0156 fea0 0000 0101 080a 2b52 5375  ...V........+RSu
	0x0030:  2b52 5374 4854 5450 2f31 2e31 2032 3030  +RStHTTP/1.1.200
	0x0040:  204f 4b0d 0a63 6f6e 7465 6e74 2d6c 656e  .OK..content-len
	0x0050:  6774 683a 2034 0d0a 636f 6e74 656e 742d  gth:.4..content-
	0x0060:  7479 7065 3a20 7465 7874 2f70 6c61 696e  type:.text/plain
	0x0070:  3b20 6368 6172 7365 743d 7574 662d 380d  ;.charset=utf-8.
	0x0080:  0a64 6174 653a 2057 6564 2c20 3331 204f  .date:.Wed,.31.O
	0x0090:  6374 2032 3031 3820 3132 3a35 323a 3435  ct.2018.12:52:45
	0x00a0:  2047 4d54 0d0a 0d0a f09f 90b2            .GMT........
21:52:45.539267 IP (tos 0x10, ttl 64, id 16553, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.47682 > 127.0.0.1.8081: Flags [.], cksum 0xfe28 (incorrect -> 0xb6f6), seq 19, ack 121, win 342, options [nop,nop,TS val 726815606 ecr 726815605], length 0
	0x0000:  4510 0034 40a9 4000 4006 fc08 7f00 0001  E..4@.@.@.......
	0x0010:  7f00 0001 ba42 1f91 2a83 4580 c47b b48b  .....B..*.E..{..
	0x0020:  8010 0156 fe28 0000 0101 080a 2b52 5376  ...V.(......+RSv
	0x0030:  2b52 5375                                +RSu
21:52:45.539433 IP (tos 0x0, ttl 64, id 45534, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47682: Flags [F.], cksum 0xfe28 (incorrect -> 0xb6f4), seq 121, ack 19, win 342, options [nop,nop,TS val 726815606 ecr 726815606], length 0
	0x0000:  4500 0034 b1de 4000 4006 8ae3 7f00 0001  E..4..@.@.......
	0x0010:  7f00 0001 1f91 ba42 c47b b48b 2a83 4580  .......B.{..*.E.
	0x0020:  8011 0156 fe28 0000 0101 080a 2b52 5376  ...V.(......+RSv
	0x0030:  2b52 5376                                +RSv
21:52:45.539609 IP (tos 0x10, ttl 64, id 16554, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.47682 > 127.0.0.1.8081: Flags [F.], cksum 0xfe28 (incorrect -> 0xb6f3), seq 19, ack 122, win 342, options [nop,nop,TS val 726815606 ecr 726815606], length 0
	0x0000:  4510 0034 40aa 4000 4006 fc07 7f00 0001  E..4@.@.@.......
	0x0010:  7f00 0001 ba42 1f91 2a83 4580 c47b b48c  .....B..*.E..{..
	0x0020:  8011 0156 fe28 0000 0101 080a 2b52 5376  ...V.(......+RSv
	0x0030:  2b52 5376                                +RSv
21:52:45.539652 IP (tos 0x0, ttl 64, id 45535, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47682: Flags [.], cksum 0xfe28 (incorrect -> 0xb6f3), seq 122, ack 20, win 342, options [nop,nop,TS val 726815606 ecr 726815606], length 0
	0x0000:  4500 0034 b1df 4000 4006 8ae2 7f00 0001  E..4..@.@.......
	0x0010:  7f00 0001 1f91 ba42 c47b b48c 2a83 4581  .......B.{..*.E.
	0x0020:  8010 0156 fe28 0000 0101 080a 2b52 5376  ...V.(......+RSv
	0x0030:  2b52 5376                                +RSv

actix_web::server::KeepAlive::Tcp(5) (same as OS)

$ telnet localhost 8081
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
GET / HTTP/1.1

HTTP/1.1 200 OK
content-length: 4
content-type: text/plain; charset=utf-8
date: Wed, 31 Oct 2018 12:59:47 GMT

🐲Connection closed by foreign host.
TRACE 2018-10-31T12:59:43Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:59:43Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:59:43Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:59:43Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:59:43Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:59:43Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:59:43Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
TRACE 2018-10-31T12:59:43Z: actix_web::middleware::logger: Access log format: %a "%r" %s %b "%{Referer}i" "%{User-Agent}i" %T
 INFO 2018-10-31T12:59:47Z: actix_web::middleware::logger: 127.0.0.1:47778 "GET / HTTP/1.1" 200 4 "-" "-" 0.002062
TRACE 2018-10-31T12:59:50Z: actix_web::server::h1: Keep-alive timeout, close connection
$ sudo tcpdump -vvv -s 0 -nX -i lo -r lo-actix-keepalive-tcp-5 port 8081
reading from file lo-actix-keepalive-tcp-5, link-type EN10MB (Ethernet)
21:59:45.000307 IP (tos 0x10, ttl 64, id 51301, offset 0, flags [DF], proto TCP (6), length 60)
    127.0.0.1.47778 > 127.0.0.1.8081: Flags [S], cksum 0xfe30 (incorrect -> 0x1584), seq 1738107018, win 43690, options [mss 65495,sackOK,TS val 727235067 ecr 0,nop,wscale 7], length 0
	0x0000:  4510 003c c865 4000 4006 7444 7f00 0001  E..<.e@.@.tD....
	0x0010:  7f00 0001 baa2 1f91 6799 688a 0000 0000  ........g.h.....
	0x0020:  a002 aaaa fe30 0000 0204 ffd7 0402 080a  .....0..........
	0x0030:  2b58 b9fb 0000 0000 0103 0307            +X..........
21:59:45.000339 IP (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6), length 60)
    127.0.0.1.8081 > 127.0.0.1.47778: Flags [S.], cksum 0xfe30 (incorrect -> 0x2ee8), seq 45284996, ack 1738107019, win 43690, options [mss 65495,sackOK,TS val 727235067 ecr 727235067,nop,wscale 7], length 0
	0x0000:  4500 003c 0000 4000 4006 3cba 7f00 0001  E..<..@.@.<.....
	0x0010:  7f00 0001 1f91 baa2 02b2 fe84 6799 688b  ............g.h.
	0x0020:  a012 aaaa fe30 0000 0204 ffd7 0402 080a  .....0..........
	0x0030:  2b58 b9fb 2b58 b9fb 0103 0307            +X..+X......
21:59:45.000369 IP (tos 0x10, ttl 64, id 51302, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.47778 > 127.0.0.1.8081: Flags [.], cksum 0xfe28 (incorrect -> 0x012d), seq 1, ack 1, win 342, options [nop,nop,TS val 727235067 ecr 727235067], length 0
	0x0000:  4510 0034 c866 4000 4006 744b 7f00 0001  E..4.f@.@.tK....
	0x0010:  7f00 0001 baa2 1f91 6799 688b 02b2 fe85  ........g.h.....
	0x0020:  8010 0156 fe28 0000 0101 080a 2b58 b9fb  ...V.(......+X..
	0x0030:  2b58 b9fb                                +X..
21:59:46.326087 IP (tos 0x10, ttl 64, id 51303, offset 0, flags [DF], proto TCP (6), length 68)
    127.0.0.1.47778 > 127.0.0.1.8081: Flags [P.], cksum 0xfe38 (incorrect -> 0x2a51), seq 1:17, ack 1, win 342, options [nop,nop,TS val 727236392 ecr 727235067], length 16
	0x0000:  4510 0044 c867 4000 4006 743a 7f00 0001  E..D.g@.@.t:....
	0x0010:  7f00 0001 baa2 1f91 6799 688b 02b2 fe85  ........g.h.....
	0x0020:  8018 0156 fe38 0000 0101 080a 2b58 bf28  ...V.8......+X.(
	0x0030:  2b58 b9fb 4745 5420 2f20 4854 5450 2f31  +X..GET./.HTTP/1
	0x0040:  2e31 0d0a                                .1..
21:59:46.326125 IP (tos 0x0, ttl 64, id 24170, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47778: Flags [.], cksum 0xfe28 (incorrect -> 0xf6c1), seq 1, ack 17, win 342, options [nop,nop,TS val 727236393 ecr 727236392], length 0
	0x0000:  4500 0034 5e6a 4000 4006 de57 7f00 0001  E..4^j@.@..W....
	0x0010:  7f00 0001 1f91 baa2 02b2 fe85 6799 689b  ............g.h.
	0x0020:  8010 0156 fe28 0000 0101 080a 2b58 bf29  ...V.(......+X.)
	0x0030:  2b58 bf28                                +X.(
21:59:47.128546 IP (tos 0x10, ttl 64, id 51304, offset 0, flags [DF], proto TCP (6), length 54)
    127.0.0.1.47778 > 127.0.0.1.8081: Flags [P.], cksum 0xfe2a (incorrect -> 0xe68a), seq 17:19, ack 1, win 342, options [nop,nop,TS val 727237195 ecr 727236393], length 2
	0x0000:  4510 0036 c868 4000 4006 7447 7f00 0001  E..6.h@.@.tG....
	0x0010:  7f00 0001 baa2 1f91 6799 689b 02b2 fe85  ........g.h.....
	0x0020:  8018 0156 fe2a 0000 0101 080a 2b58 c24b  ...V.*......+X.K
	0x0030:  2b58 bf29 0d0a                           +X.)..
21:59:47.128591 IP (tos 0x0, ttl 64, id 24171, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47778: Flags [.], cksum 0xfe28 (incorrect -> 0xf07a), seq 1, ack 19, win 342, options [nop,nop,TS val 727237195 ecr 727237195], length 0
	0x0000:  4500 0034 5e6b 4000 4006 de56 7f00 0001  E..4^k@.@..V....
	0x0010:  7f00 0001 1f91 baa2 02b2 fe85 6799 689d  ............g.h.
	0x0020:  8010 0156 fe28 0000 0101 080a 2b58 c24b  ...V.(......+X.K
	0x0030:  2b58 c24b                                +X.K
21:59:47.131402 IP (tos 0x0, ttl 64, id 24172, offset 0, flags [DF], proto TCP (6), length 172)
    127.0.0.1.8081 > 127.0.0.1.47778: Flags [P.], cksum 0xfea0 (incorrect -> 0xf197), seq 1:121, ack 19, win 342, options [nop,nop,TS val 727237198 ecr 727237195], length 120
	0x0000:  4500 00ac 5e6c 4000 4006 dddd 7f00 0001  E...^l@.@.......
	0x0010:  7f00 0001 1f91 baa2 02b2 fe85 6799 689d  ............g.h.
	0x0020:  8018 0156 fea0 0000 0101 080a 2b58 c24e  ...V........+X.N
	0x0030:  2b58 c24b 4854 5450 2f31 2e31 2032 3030  +X.KHTTP/1.1.200
	0x0040:  204f 4b0d 0a63 6f6e 7465 6e74 2d6c 656e  .OK..content-len
	0x0050:  6774 683a 2034 0d0a 636f 6e74 656e 742d  gth:.4..content-
	0x0060:  7479 7065 3a20 7465 7874 2f70 6c61 696e  type:.text/plain
	0x0070:  3b20 6368 6172 7365 743d 7574 662d 380d  ;.charset=utf-8.
	0x0080:  0a64 6174 653a 2057 6564 2c20 3331 204f  .date:.Wed,.31.O
	0x0090:  6374 2032 3031 3820 3132 3a35 393a 3437  ct.2018.12:59:47
	0x00a0:  2047 4d54 0d0a 0d0a f09f 90b2            .GMT........
21:59:47.131449 IP (tos 0x10, ttl 64, id 51305, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.47778 > 127.0.0.1.8081: Flags [.], cksum 0xfe28 (incorrect -> 0xeffc), seq 19, ack 121, win 342, options [nop,nop,TS val 727237198 ecr 727237198], length 0
	0x0000:  4510 0034 c869 4000 4006 7448 7f00 0001  E..4.i@.@.tH....
	0x0010:  7f00 0001 baa2 1f91 6799 689d 02b2 fefd  ........g.h.....
	0x0020:  8010 0156 fe28 0000 0101 080a 2b58 c24e  ...V.(......+X.N
	0x0030:  2b58 c24e                                +X.N
21:59:50.001987 IP (tos 0x0, ttl 64, id 24173, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47778: Flags [F.], cksum 0xfe28 (incorrect -> 0xe4c5), seq 121, ack 19, win 342, options [nop,nop,TS val 727240068 ecr 727237198], length 0
	0x0000:  4500 0034 5e6d 4000 4006 de54 7f00 0001  E..4^m@.@..T....
	0x0010:  7f00 0001 1f91 baa2 02b2 fefd 6799 689d  ............g.h.
	0x0020:  8011 0156 fe28 0000 0101 080a 2b58 cd84  ...V.(......+X..
	0x0030:  2b58 c24e                                +X.N
21:59:50.002168 IP (tos 0x10, ttl 64, id 51306, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.47778 > 127.0.0.1.8081: Flags [F.], cksum 0xfe28 (incorrect -> 0xd98d), seq 19, ack 122, win 342, options [nop,nop,TS val 727240069 ecr 727240068], length 0
	0x0000:  4510 0034 c86a 4000 4006 7447 7f00 0001  E..4.j@.@.tG....
	0x0010:  7f00 0001 baa2 1f91 6799 689d 02b2 fefe  ........g.h.....
	0x0020:  8011 0156 fe28 0000 0101 080a 2b58 cd85  ...V.(......+X..
	0x0030:  2b58 cd84                                +X..
21:59:50.002225 IP (tos 0x0, ttl 64, id 24174, offset 0, flags [DF], proto TCP (6), length 52)
    127.0.0.1.8081 > 127.0.0.1.47778: Flags [.], cksum 0xfe28 (incorrect -> 0xd98c), seq 122, ack 20, win 342, options [nop,nop,TS val 727240069 ecr 727240069], length 0
	0x0000:  4500 0034 5e6e 4000 4006 de53 7f00 0001  E..4^n@.@..S....
	0x0010:  7f00 0001 1f91 baa2 02b2 fefe 6799 689e  ............g.h.
	0x0020:  8010 0156 fe28 0000 0101 080a 2b58 cd85  ...V.(......+X..
	0x0030:  2b58 cd85                                +X..

@legokichi

This comment has been minimized.

legokichi commented Nov 1, 2018

if msg.keep_alive().unwrap_or_else(|| req.keep_alive()) {
self.flags = Flags::STARTED | Flags::KEEPALIVE;
} else {
self.flags = Flags::STARTED;
}

This code does not always give connection close header.

Why dont you use self.settings.keep_alive_enabled() ?

if msg.keep_alive().unwrap_or_else(|| self.settings.keep_alive_enabled()) {
@DoumanAsh

This comment has been minimized.

Contributor

DoumanAsh commented Nov 1, 2018

@legokichi I think in this case it is supposed to be set in either request or response already.
Though I need to re-check code to be sure

UPD: Settings are used here to determine whether we should start keep-alive timer itself

actix-web/src/server/h1.rs

Lines 93 to 123 in cfd9a56

let addr = stream.peer_addr();
let (ka_expire, ka_timer) = if let Some(delay) = keepalive_timer {
(delay.deadline(), Some(delay))
} else if let Some(delay) = settings.keep_alive_timer() {
(delay.deadline(), Some(delay))
} else {
(settings.now(), None)
};
let flags = if is_eof {
Flags::READ_DISCONNECTED | Flags::FLUSHED
} else if settings.keep_alive_enabled() {
Flags::KEEPALIVE | Flags::KEEPALIVE_ENABLED | Flags::FLUSHED
} else {
Flags::empty()
};
Http1Dispatcher {
stream: H1Writer::new(stream, settings.clone()),
decoder: H1Decoder::new(),
payload: None,
tasks: VecDeque::new(),
error: None,
flags,
addr,
buf,
settings,
ka_timer,
ka_expire,
}
}

Though looking at how we set headers I wonder if we're actually doing it wrong as on HTTP1.1 we should set keep-alive to connection when keep-alive is on, and Close otherwise, while for HTTP1.0 it is always by default should be close and we don't even need to set it

@fafhrd91 What do you think?

UPD: though maybe we need to set keep-alive for HTTP1.0, but I think we should set it for HTTP1.1 too

@legokichi

This comment has been minimized.

legokichi commented Nov 1, 2018

Relating to #439 (comment) ,

I confirmed that function poll_flush(true) will never be called when ::actix_web::server::KeepAlive::Timeout(5)
Http1Dispatcher::poll will not be polled after 5 seconds.
No timer will fire.

I checked on master branch today.

@DoumanAsh

This comment has been minimized.

Contributor

DoumanAsh commented Nov 1, 2018

Thanks! It is strange because we should set shutdown flag on expiration of timer. I'll try to check code there again when I'll have time

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Nov 1, 2018

@DoumanAsh i'll handle this

@legokichi

This comment has been minimized.

legokichi commented Nov 5, 2018

Probably this is necessary.

diff --git a/src/server/h1.rs b/src/server/h1.rs
index a2ffc055..3003a4ac 100644
--- a/src/server/h1.rs
+++ b/src/server/h1.rs
@@ -192,6 +192,7 @@ where

     #[inline]
     pub fn poll(&mut self) -> Poll<(), HttpDispatchError> {
+        ::futures::task::current().notify();
         // check connection keep-alive
         self.poll_keepalive()?;
@DoumanAsh

This comment has been minimized.

Contributor

DoumanAsh commented Nov 5, 2018

notify forces tokio to poll future again, which should only be ever necessary when we return NotReady and no IO is scheduled

@fafhrd91

This comment has been minimized.

Member

fafhrd91 commented Nov 8, 2018

@legokichi should be fixed in master

@neowutran could you test master again?

@neowutran

This comment has been minimized.

neowutran commented Nov 12, 2018

Testing with live traffic,
service is running for 3 days, no unclosed connection for the moment : )
I will let it run for few more days
( however, there are still some memory leak, from 0.1% to 8% in 3 days )

@legokichi

This comment has been minimized.

legokichi commented Nov 13, 2018

seems good.

@neowutran

This comment has been minimized.

neowutran commented Nov 13, 2018

Didn't saw any unclosed connection yet, but a lot of memory leak. Crashed once by out of memory, relaunched, and now needed to stop the service as I released a new version of my software, so much more traffic on live

valgrind log when I stopped the service:
https://neowutran.ovh/valgrind_debug9999.err

used the "/shutdown" to close it gracefully

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment