Bug 219644 - FreeBSD 11 + nginx + apache delay +0.1 second on files greater than 32768 bytes
Summary: FreeBSD 11 + nginx + apache delay +0.1 second on files greater than 32768 bytes
Status: Closed FIXED
Alias: None
Product: Base System
Classification: Unclassified
Component: kern (show other bugs)
Version: 11.0-RELEASE
Hardware: amd64 Any
: --- Affects Many People
Assignee: Lawrence Stewart
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-05-29 21:44 UTC by Alexey Koscheev
Modified: 2023-06-26 18:47 UTC (History)
6 users (show)

See Also:

Attachments
test file (size large than 32768 bytes) (34.38 KB, text/plain)
2017-05-29 21:44 UTC, Alexey Koscheev 		no flags Details
kdump -E -f nginx > nginx.txt (51.88 KB, text/plain)
2017-05-29 21:45 UTC, Alexey Koscheev 		no flags Details
kdump -E -f apache > apache.txt (9.41 KB, text/plain)
2017-05-29 21:46 UTC, Alexey Koscheev 		no flags Details
nginx ktrace on FreeBSD10 (51.74 KB, text/plain)
2017-05-30 10:29 UTC, Alexey Koscheev 		no flags Details
apache ktrace on FreeBSD10 (9.31 KB, text/plain)
2017-05-30 10:30 UTC, Alexey Koscheev 		no flags Details
tcpdump on FresBSD10 (2.08 KB, text/plain)
2017-05-30 10:31 UTC, Alexey Koscheev 		no flags Details
tcpdump on FresBSD11 (2.00 KB, text/plain)
2017-05-30 10:31 UTC, Alexey Koscheev 		no flags Details
View All Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description Alexey Koscheev 2017-05-29 21:44:36 UTC 
Created attachment 183041 [details]
test file (size large than 32768 bytes)

FreeBSD freebsd11.build.ihead.ru 11.0-RELEASE-p8 FreeBSD 11.0-RELEASE-p8 #0: Wed Feb 22 06:12:04 UTC 2017     root@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC  amd64

Proxy requests from nginx to apache.
If apache response more than 32768 bytes (with headers) the request longed on ~0.1 second.

How to reproduce.
1. In httpd.conf add
Listen 127.0.0.1:80
MaxClients 1

2. Add ihead.txt in DocumentRoot (/usr/local/www/apache24/data).
It may be any file larger than 32768 bytes.

3. In nginx.conf in server {...} add 
location /ihead.txt {
proxy_pass http://127.0.0.1:80;
}

4. find nginx and apache PIDs
ps -aux | grep nginx
ps -aux | grep httpd

5. run ktrace on finded PIDs 
ktrace -p 42260 -t cfinpstuwy -f nginx
ktrace -p 42184 -t cfinpstuwy -f apache

6. Request http://IP_nginx/ihead.txt

7. Stop ktrace
ktrace -C

8. Make dumps readable
kdump -E -f nginx > nginx.txt
kdump -E -f apache > apache.txt

9. There is +0.1 second delay
 42260 nginx    0.004903 CSW   stop kernel "kqread"
 42260 nginx    0.110929 CSW   resume kernel "kqread" 
 
 42184 httpd    0.000591 CSW   stop kernel "select"
 42184 httpd    0.199081 CSW   resume kernel "select"


Problem not reproduced on FreeBSD 10.
Comment 1 Alexey Koscheev 2017-05-29 21:45:42 UTC 
Created attachment 183042 [details]
kdump -E -f nginx > nginx.txt
Comment 2 Alexey Koscheev 2017-05-29 21:46:20 UTC 
Created attachment 183043 [details]
kdump -E -f apache > apache.txt
Comment 3 Maxim Konovalov freebsd_committer freebsd_triage 2017-05-30 09:21:26 UTC 
Hello,

As was suggested in nginx trac ticket gathering tcpdump on FreeBSD 11 and 10 would be useful as well.

Also, comparing problematic traces with FreeBSD 10 is also a good idea.
Comment 4 Alexey Koscheev 2017-05-30 10:29:56 UTC 
Created attachment 183061 [details]
nginx ktrace on FreeBSD10
Comment 5 Alexey Koscheev 2017-05-30 10:30:35 UTC 
Created attachment 183062 [details]
apache ktrace on FreeBSD10
Comment 6 Alexey Koscheev 2017-05-30 10:31:11 UTC 
Created attachment 183063 [details]
tcpdump on FresBSD10
Comment 7 Alexey Koscheev 2017-05-30 10:31:43 UTC 
Created attachment 183064 [details]
tcpdump on FresBSD11
Comment 8 Alexey Koscheev 2017-05-30 10:33:41 UTC 
sysctl net.inet.tcp.delayed_ack
net.inet.tcp.delayed_ack: 1

sysctl net.inet.tcp.delacktime
net.inet.tcp.delacktime: 100

1)
sysctl net.inet.tcp.delayed_ack=0
net.inet.tcp.delayed_ack: 1 -> 0

Problem is not reproduced.

2)
sysctl net.inet.tcp.delayed_ack=1
net.inet.tcp.delayed_ack: 0 -> 1

sysctl net.inet.tcp.delacktime=200
net.inet.tcp.delacktime: 100 -> 200

Problem is reproduced with +0.2 seconds delay.
Comment 9 Maxim Konovalov freebsd_committer freebsd_triage 2017-05-30 11:07:09 UTC 
What are delayed_ack settings on your FreeBSD 10 system?

Are they non default?
Comment 10 Alexey Koscheev 2017-05-30 11:40:05 UTC 
(In reply to Maxim Konovalov from comment #9)

Defaults are:

sysctl net.inet.tcp.delayed_ack
net.inet.tcp.delayed_ack: 1

sysctl net.inet.tcp.delacktime
net.inet.tcp.delacktime: 100
Comment 11 Alexey Koscheev 2017-05-30 11:42:11 UTC 
(In reply to Maxim Konovalov from comment #9)

[root@freebsd10 ~]# uname -a
FreeBSD freebsd10.build.ihead.ru 10.3-RELEASE-p18 FreeBSD 10.3-RELEASE-p18 #0: Tue Apr 11 10:31:00 UTC 2017     root@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC  amd64
[root@freebsd10 ~]# sysctl net.inet.tcp.delayed_ack
net.inet.tcp.delayed_ack: 1
[root@freebsd10 ~]# sysctl sysctl net.inet.tcp.delacktime
net.inet.tcp.delacktime: 100
Comment 12 Maxim Konovalov freebsd_committer freebsd_triage 2017-05-30 12:08:58 UTC 
Can you share please "sysctl net.inet.tcp" on your FreeBSD 10 and FreeBSD 11?
Comment 13 Alexey Koscheev 2017-05-30 12:20:49 UTC 
(In reply to Maxim Konovalov from comment #12)

[root@freebsd10 ~]# sysctl net.inet.tcp
net.inet.tcp.rfc1323: 1
net.inet.tcp.mssdflt: 536
net.inet.tcp.keepidle: 7200000
net.inet.tcp.keepintvl: 75000
net.inet.tcp.sendspace: 32768
net.inet.tcp.recvspace: 65536
net.inet.tcp.keepinit: 75000
net.inet.tcp.delacktime: 100
net.inet.tcp.v6mssdflt: 1220
net.inet.tcp.nolocaltimewait: 0
net.inet.tcp.maxtcptw: 12950
net.inet.tcp.per_cpu_timers: 0
net.inet.tcp.v6pmtud_blackhole_mss: 1220
net.inet.tcp.pmtud_blackhole_mss: 1200
net.inet.tcp.pmtud_blackhole_failed: 0
net.inet.tcp.pmtud_blackhole_activated_min_mss: 0
net.inet.tcp.pmtud_blackhole_activated: 0
net.inet.tcp.pmtud_blackhole_detection: 0
net.inet.tcp.rexmit_drop_options: 0
net.inet.tcp.keepcnt: 8
net.inet.tcp.finwait2_timeout: 60000
net.inet.tcp.fast_finwait2_recycle: 0
net.inet.tcp.always_keepalive: 1
net.inet.tcp.rexmit_slop: 200
net.inet.tcp.rexmit_min: 30
net.inet.tcp.msl: 30000
net.inet.tcp.persmax: 60000
net.inet.tcp.persmin: 5000
net.inet.tcp.syncache.rst_on_sock_fail: 1
net.inet.tcp.syncache.rexmtlimit: 3
net.inet.tcp.syncache.hashsize: 512
net.inet.tcp.syncache.count: 0
net.inet.tcp.syncache.cachelimit: 15375
net.inet.tcp.syncache.bucketlimit: 30
net.inet.tcp.syncookies_only: 0
net.inet.tcp.syncookies: 1
net.inet.tcp.soreceive_stream: 0
net.inet.tcp.isn_reseed_interval: 0
net.inet.tcp.icmp_may_rst: 1
net.inet.tcp.pcbcount: 4
net.inet.tcp.do_tcpdrain: 1
net.inet.tcp.tcbhashsize: 16384
net.inet.tcp.log_debug: 0
net.inet.tcp.minmss: 216
net.inet.tcp.sack.globalholes: 0
net.inet.tcp.sack.globalmaxholes: 65536
net.inet.tcp.sack.maxholes: 128
net.inet.tcp.sack.enable: 1
net.inet.tcp.reass.overflows: 9
net.inet.tcp.reass.cursegments: 0
net.inet.tcp.reass.maxsegments: 7900
net.inet.tcp.sendbuf_max: 2097152
net.inet.tcp.sendbuf_inc: 8192
net.inet.tcp.sendbuf_auto: 1
net.inet.tcp.tso: 1
net.inet.tcp.path_mtu_discovery: 1
net.inet.tcp.recvbuf_max: 2097152
net.inet.tcp.recvbuf_inc: 16384
net.inet.tcp.recvbuf_auto: 1
net.inet.tcp.insecure_rst: 0
net.inet.tcp.ecn.maxretries: 1
net.inet.tcp.ecn.enable: 0
net.inet.tcp.abc_l_var: 2
net.inet.tcp.rfc3465: 1
net.inet.tcp.experimental.initcwnd10: 1
net.inet.tcp.rfc3390: 1
net.inet.tcp.rfc3042: 1
net.inet.tcp.do_pipe: 0
net.inet.tcp.drop_synfin: 0
net.inet.tcp.delayed_ack: 1
net.inet.tcp.blackhole: 0
net.inet.tcp.log_in_vain: 0
net.inet.tcp.hostcache.purge: 0
net.inet.tcp.hostcache.prune: 300
net.inet.tcp.hostcache.expire: 3600
net.inet.tcp.hostcache.count: 0
net.inet.tcp.hostcache.bucketlimit: 30
net.inet.tcp.hostcache.hashsize: 512
net.inet.tcp.hostcache.cachelimit: 15360
net.inet.tcp.cc.available: newreno
net.inet.tcp.cc.algorithm: newreno

[root@freebsd11 ~]# sysctl net.inet.tcp
net.inet.tcp.rfc1323: 1
net.inet.tcp.mssdflt: 536
net.inet.tcp.keepidle: 7200000
net.inet.tcp.keepintvl: 75000
net.inet.tcp.sendspace: 32768
net.inet.tcp.recvspace: 65536
net.inet.tcp.keepinit: 75000
net.inet.tcp.delacktime: 100
net.inet.tcp.v6mssdflt: 1220
net.inet.tcp.nolocaltimewait: 0
net.inet.tcp.maxtcptw: 12900
net.inet.tcp.per_cpu_timers: 0
net.inet.tcp.v6pmtud_blackhole_mss: 1220
net.inet.tcp.pmtud_blackhole_mss: 1200
net.inet.tcp.pmtud_blackhole_failed: 0
net.inet.tcp.pmtud_blackhole_activated_min_mss: 0
net.inet.tcp.pmtud_blackhole_activated: 0
net.inet.tcp.pmtud_blackhole_detection: 0
net.inet.tcp.rexmit_drop_options: 0
net.inet.tcp.keepcnt: 8
net.inet.tcp.finwait2_timeout: 60000
net.inet.tcp.fast_finwait2_recycle: 0
net.inet.tcp.always_keepalive: 1
net.inet.tcp.rexmit_slop: 200
net.inet.tcp.rexmit_min: 30
net.inet.tcp.msl: 30000
net.inet.tcp.persmax: 60000
net.inet.tcp.persmin: 5000
net.inet.tcp.syncache.rst_on_sock_fail: 1
net.inet.tcp.syncache.rexmtlimit: 3
net.inet.tcp.syncache.hashsize: 512
net.inet.tcp.syncache.count: 0
net.inet.tcp.syncache.cachelimit: 15364
net.inet.tcp.syncache.bucketlimit: 30
net.inet.tcp.syncookies_only: 0
net.inet.tcp.syncookies: 1
net.inet.tcp.functions_available:
Stack                           D PCB count
default                         * 4

net.inet.tcp.functions_default: default
net.inet.tcp.soreceive_stream: 0
net.inet.tcp.isn_reseed_interval: 0
net.inet.tcp.icmp_may_rst: 1
net.inet.tcp.pcbcount: 4
net.inet.tcp.do_tcpdrain: 1
net.inet.tcp.tcbhashsize: 16384
net.inet.tcp.log_debug: 0
net.inet.tcp.minmss: 216
net.inet.tcp.sack.globalholes: 0
net.inet.tcp.sack.globalmaxholes: 65536
net.inet.tcp.sack.maxholes: 128
net.inet.tcp.sack.enable: 1
net.inet.tcp.reass.cursegments: 0
net.inet.tcp.reass.maxsegments: 7900
net.inet.tcp.sendbuf_max: 2097152
net.inet.tcp.sendbuf_inc: 8192
net.inet.tcp.sendbuf_auto: 1
net.inet.tcp.tso: 1
net.inet.tcp.path_mtu_discovery: 1
net.inet.tcp.recvbuf_max: 2097152
net.inet.tcp.recvbuf_inc: 16384
net.inet.tcp.recvbuf_auto: 1
net.inet.tcp.insecure_rst: 0
net.inet.tcp.insecure_syn: 0
net.inet.tcp.ecn.maxretries: 1
net.inet.tcp.ecn.enable: 2
net.inet.tcp.abc_l_var: 2
net.inet.tcp.rfc3465: 1
net.inet.tcp.initcwnd_segments: 10
net.inet.tcp.rfc3390: 1
net.inet.tcp.rfc3042: 1
net.inet.tcp.rfc6675_pipe: 0
net.inet.tcp.drop_synfin: 0
net.inet.tcp.delayed_ack: 1
net.inet.tcp.blackhole: 0
net.inet.tcp.log_in_vain: 0
net.inet.tcp.hostcache.purgenow: 0
net.inet.tcp.hostcache.purge: 0
net.inet.tcp.hostcache.prune: 300
net.inet.tcp.hostcache.expire: 3600
net.inet.tcp.hostcache.count: 0
net.inet.tcp.hostcache.bucketlimit: 30
net.inet.tcp.hostcache.hashsize: 512
net.inet.tcp.hostcache.cachelimit: 15360
net.inet.tcp.cc.available: newreno
net.inet.tcp.cc.algorithm: newreno
Comment 14 Maxim Konovalov freebsd_committer freebsd_triage 2017-05-30 13:58:02 UTC 
Can you also share your nginx.conf from both systems please?
Comment 15 Alexey Koscheev 2017-05-30 14:02:30 UTC 
(In reply to Maxim Konovalov from comment #14)

nginx.conf is identical on both systems.


#user  nobody;
worker_processes  1;

#error_log  logs/error.log;
#error_log  logs/error.log  notice;
#error_log  logs/error.log  info;

#pid        logs/nginx.pid;


events {
    worker_connections  1024;
}


http {
    include       mime.types;
    default_type  application/octet-stream;

    #log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
    #                  '$status $body_bytes_sent "$http_referer" '
    #                  '"$http_user_agent" "$http_x_forwarded_for"';

    #access_log  logs/access.log  main;

    sendfile        on;
    #tcp_nopush     on;

    #keepalive_timeout  0;
    keepalive_timeout  65;

    #gzip  on;

    server {
        listen       80;
        server_name  localhost;

        #charset koi8-r;

        #access_log  logs/host.access.log  main;

        location / {
            root   html;
            index  index.html index.htm;
        }

        #error_page  404              /404.html;

        # redirect server error pages to the static page /50x.html
        #
        error_page   500 502 503 504  /50x.html;
        location = /50x.html {
            root   html;
        }

        # proxy the PHP scripts to Apache listening on 127.0.0.1:80
        #
        #location ~ \.php$ {
        #    proxy_pass   http://127.0.0.1;
        #}

        # pass the PHP scripts to FastCGI server listening on 127.0.0.1:9000
        #
        #location ~ \.php$ {
        #    root           html;
        #    fastcgi_pass   127.0.0.1:9000;
        #    fastcgi_index  index.php;
        #    fastcgi_param  SCRIPT_FILENAME  /scripts$fastcgi_script_name;
        #    include        fastcgi_params;
        #}

        # deny access to .htaccess files, if Apache's document root
        # concurs with nginx's one
        #
        #location ~ /\.ht {
        #    deny  all;
        #}

location /ihead.txt {
proxy_pass http://127.0.0.1:80;
}
    }

}
Comment 16 Maxim Konovalov freebsd_committer freebsd_triage 2017-06-01 08:50:23 UTC 
Hello,

I haven't had a change to dig further so far but just noticed this bug report:

https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=211003

It could be related to the issue you observe.

Can you try to update FreeBSD 11.0 to @319397 and check if it still manifest itself?

Thanks,

Maxim
Comment 17 Alexey Koscheev 2017-06-01 18:51:51 UTC 
(In reply to Maxim Konovalov from comment #16)
Hi.
I got diff from https://svnweb.freebsd.org/base?view=revision&revision=319397 rebuild and install kernel.

It did not help.
Comment 18 Alexey Koscheev 2017-06-11 20:12:56 UTC 
Can anybody help with this?
Is is easy reproduceble FreeBSD11's strange behavior.
Comment 19 Maxim Konovalov freebsd_committer freebsd_triage 2017-06-13 16:36:06 UTC 
Can you run one more experiments for me please?  Specifically re-run your test with the following sysctl before:

sysctl net.inet.tcp.initcwnd_segments=40

Thanks,

Maxim
Comment 20 Alexey Koscheev 2017-06-13 17:58:04 UTC 
(In reply to Maxim Konovalov from comment #19)

sysctl net.inet.tcp.initcwnd_segments=40
net.inet.tcp.initcwnd_segments: 10 -> 40

result: no problem
Comment 21 Alexey Koscheev 2017-08-10 14:55:57 UTC 
Problem is reproduced on FreeBSD 11.1.

FreeBSD 11.1-RELEASE-p1 #0: Wed Aug  9 11:55:48 UTC 2017     root@amd64-builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC  amd64

Why nobody cares about it?
Comment 22 Maxim Konovalov freebsd_committer freebsd_triage 2017-08-10 15:05:00 UTC 
(In reply to freebsd from comment #21)

You've got the workaround, right?  Does it work for you?
Comment 23 Alexey Koscheev 2017-08-10 15:13:21 UTC 
Yes, I have workaround (sysctl net.inet.tcp.delayed_ack=0) and it works.
But I not sure is it ok, and what problems it may bring in other parts of network stack.

By the way, the problem exists on default setup, and this is not good.
People may think, that FreeBSD is slow.
Comment 24 v.chernyadev 2018-09-17 11:42:55 UTC 
This is still relevant for us. When to wait for correction?
Comment 25 Lawrence Stewart freebsd_committer freebsd_triage 2018-10-09 02:58:11 UTC 
Apologies, I had completely forgotten about this issue. Thanks for the reminder.
Comment 26 Jochen Neumeister freebsd_committer freebsd_triage 2019-02-11 11:16:02 UTC 
(In reply to Lawrence Stewart from comment #25)

ping :-)
Comment 27 Alexey Koscheev 2020-02-24 19:23:01 UTC 
Problem still present in 11.3-RELEASE-p6 and 12.1-RELEASE-p2.
Comment 28 Alexey Koscheev 2020-12-14 20:43:01 UTC 
Problem still present in 12.2-RELEASE-p2: +~35ms per request with default net.inet.tcp.delayed_ack=1.
Comment 29 Jochen Neumeister freebsd_committer freebsd_triage 2022-01-24 07:45:02 UTC 
(In reply to Lawrence Stewart from comment #25)

gentle ping again
Comment 30 Alexey Koscheev 2023-06-20 19:17:18 UTC 
I currently unable to reproduce the bug on 12.3-RELEASE-p5 and 12.4-RELEASE-p2.
Seems it was fixed.
Comment 31 Maxim Konovalov freebsd_committer freebsd_triage 2023-06-26 18:47:17 UTC 
Let's mark it as "mysteriously fixed".