Help! Caddy reverse proxy introduces long delay in response

Help
1

Running latest caddy docker image using :alpine tag. I’ve indirectly noticed the issue since I started with one of the betas but didn’t track it down because I am just exploring a deployment pattern. Now I took the time to figure it out and it appears to be Caddy and not the application image. Is anyone able to tell me why my Caddy configuration is so slow?

The timing below indicates that Caddy is adding ~4s to the response time.

I am experiencing an odd delay when accessing the application through caddy. measure-http-response-time.sh just wraps apache benchmark (ab) and makes sure there are no failures then parses and outputs the average request time to stdout for capture.

This one hits the app container directly:

vagrant@vagrant:/vagrant$ tests/measure-http-response-time.sh 2 http://ip-172-31-52-163.ec2.internal:5000/_health/
Pass: All requests completed
Pass: No Failed Reports
Time per request: 59.397 [ms] (mean)
59.397

This one sends the request to caddy:

vagrant@vagrant:/vagrant$ tests/measure-http-response-time.sh 2 http://ip-172-31-52-163.ec2.internal/_health/
Pass: All requests completed
Pass: No Failed Reports
Time per request: 4068.198 [ms] (mean)
4068.198

Here is the caddy json:

$ cat /var/app/current/templates/Caddyfile.json
{
    "admin": {
        "disabled": true
    },
    "apps": {
        "http": {
            "servers": {
                "srv0": {
                    "automatic_https": {
                        "disable_redirects": true
                    },
                    "listen": [
                        ":80",
                        ":443"
                    ],
                    "routes": [
                        {
                            "handle": [
                                {
                                    "handler": "subroute",
                                    "routes": [
                                        {
                                            "handle": [
                                                {
                                                    "buffer_requests": true,
                                                    "handler": "reverse_proxy",
                                                    "upstreams": [
                                                        {
                                                            "dial": "web:5000"
                                                        }
                                                    ]
                                                }
                                            ]
                                        }
                                    ]
                                }
                            ],
                            "terminal": true
                        }
                    ],
                    "tls_connection_policies": [
                        {
                            "default_sni": "example.com"
                        }
                    ]
                }
            }
        },
        "tls": {
            "automation": {
                "policies": [
                    {
                        "issuer": {
                            "email": "foo@example.com",
                            "module": "acme"
                        },
                        "on_demand": true
                    }
                ]
            }
        }
    },
    "logging": {
        "logs": {
            "default": {
                "level": "DEBUG"
            }
        }
    }
}
2

My best guess is that it’s due to response buffering. If you turn that off, how does it behave?

3

Also what are the full Caddy logs? (Unredacted and complete please)

4

Okay so here goes… nothing that jumps out at me but I hope you see something =)

Here is the request generator:

vagrant@vagrant:~$ cd /vagrant
vagrant@vagrant:/vagrant$ tests/measure-http-response-time.sh 5 http://ip-172-31-4-246.ec2.internal:5000/_health/
Pass: All requests completed
Pass: No Failed Reports
Time per request: 64.698 [ms] (mean)
64.698
vagrant@vagrant:/vagrant$ tests/measure-http-response-time.sh 5 http://ip-172-31-4-246.ec2.internal/_health/
Pass: All requests completed
Pass: No Failed Reports
Time per request: 3800.361 [ms] (mean)
3800.361
vagrant@vagrant:/vagrant$

Here are the docker logs on the ec2 host:

[root@ip-172-31-4-246 ec2-user]# docker logs 1fe 2> output.log
[root@ip-172-31-4-246 ec2-user]# cat output.log
{"level":"info","ts":1586267511.4893467,"msg":"using provided configuration","config_file":"/etc/caddy/Caddyfile.json","config_adapter":""}
{"level":"warn","ts":1586267511.4897754,"logger":"admin","msg":"admin endpoint disabled"}
2020/04/07 13:51:51 [INFO][cache:0xc000332870] Started certificate maintenance routine
{"level":"info","ts":1586267511.5770144,"logger":"tls","msg":"cleaned up storage units"}
{"level":"debug","ts":1586267511.5797288,"logger":"http","msg":"starting server loop","address":"[::]:80","http3":false,"tls":false}
{"level":"debug","ts":1586267511.5804248,"logger":"http","msg":"starting server loop","address":"[::]:443","http3":false,"tls":true}
{"level":"info","ts":1586267511.580546,"msg":"autosaved config","file":"/config/caddy/autosave.json"}
{"level":"info","ts":1586267511.5805566,"msg":"serving initial configuration"}
{"level":"debug","ts":1586267517.7501707,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:51:57 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":4.047934424,"status":200}
{"level":"debug","ts":1586267524.5809896,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:52:04 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":0.881458087,"status":200}
{"level":"debug","ts":1586267524.582245,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"Accept":["*/*"],"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:52:04 GMT"]},"duration":4.00582699,"status":200}
{"level":"debug","ts":1586267534.5807772,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:52:14 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":0.881993506,"status":200}
{"level":"debug","ts":1586267534.5822039,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:52:14 GMT"]},"duration":4.006082446,"status":200}
{"level":"debug","ts":1586267544.57949,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:52:24 GMT"]},"duration":0.880635968,"status":200}
{"level":"debug","ts":1586267544.580921,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:52:24 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":4.005514362,"status":200}
{"level":"debug","ts":1586267554.5802798,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:52:34 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":0.881088336,"status":200}
{"level":"debug","ts":1586267554.5813584,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:52:34 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":4.005540764,"status":200}
{"level":"debug","ts":1586267564.5804784,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:52:44 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":0.882079165,"status":200}
{"level":"debug","ts":1586267564.5815897,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:52:44 GMT"]},"duration":4.005741952,"status":200}
{"level":"debug","ts":1586267574.5813675,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Date":["Tue, 07 Apr 2020 13:52:54 GMT"],"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"]},"duration":4.004794574,"status":200}
{"level":"debug","ts":1586267574.5829096,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"Accept":["*/*"],"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:52:54 GMT"]},"duration":0.884323223,"status":200}
{"level":"debug","ts":1586267584.6228886,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:04 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":0.924157332,"status":200}
{"level":"debug","ts":1586267584.6240458,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"Accept":["*/*"],"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:04 GMT"]},"duration":4.046752959,"status":200}
{"level":"debug","ts":1586267584.6252253,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.0","remote_addr":"172.28.14.109:60835","host":"ip-172-31-4-246.ec2.internal","headers":{"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"],"X-Forwarded-For":["172.28.14.109"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:04 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":2.606528891,"status":200}
{"level":"debug","ts":1586267588.6942234,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.0","remote_addr":"172.28.14.109:60836","host":"ip-172-31-4-246.ec2.internal","headers":{"X-Forwarded-For":["172.28.14.109"],"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:08 GMT"]},"duration":4.004543377,"status":200}
{"level":"debug","ts":1586267592.7623851,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:12 GMT"]},"duration":2.185481109,"status":200}
{"level":"debug","ts":1586267592.7639701,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.0","remote_addr":"172.28.14.109:60837","host":"ip-172-31-4-246.ec2.internal","headers":{"X-Forwarded-For":["172.28.14.109"],"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:12 GMT"]},"duration":4.006091289,"status":200}
{"level":"debug","ts":1586267596.8449883,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.0","remote_addr":"172.28.14.109:60838","host":"ip-172-31-4-246.ec2.internal","headers":{"X-Forwarded-For":["172.28.14.109"],"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"headers":{"Date":["Tue, 07 Apr 2020 13:53:16 GMT"],"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"]},"duration":4.004229874,"status":200}
{"level":"debug","ts":1586267596.846686,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:16 GMT"]},"duration":3.147625527,"status":200}
{"level":"debug","ts":1586267600.9497545,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.0","remote_addr":"172.28.14.109:60839","host":"ip-172-31-4-246.ec2.internal","headers":{"X-Forwarded-For":["172.28.14.109"],"User-Agent":["ApacheBench/2.3"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:20 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":4.004512102,"status":200}
{"level":"debug","ts":1586267600.9510288,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"Accept":["*/*"],"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:20 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":0.373655015,"status":200}
{"level":"debug","ts":1586267607.70461,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:27 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":4.006394898,"status":200}
{"level":"debug","ts":1586267614.5827413,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:34 GMT"]},"duration":4.004667755,"status":200}
{"level":"debug","ts":1586267614.5844116,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:34 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":0.885970056,"status":200}
{"level":"debug","ts":1586267623.376046,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47974","host":"production.pages.pendleton.systems","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["curl/7.67.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:43 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":4.004487141,"status":200}
{"level":"debug","ts":1586267623.3773088,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:43 GMT"]},"duration":2.79974674,"status":200}
{"level":"debug","ts":1586267627.703219,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Content-Type":["text/html; charset=utf-8"],"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:47 GMT"]},"duration":4.004633631,"status":200}
{"level":"debug","ts":1586267634.5841048,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"],"X-Forwarded-For":["172.31.16.62"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:54 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":0.886199545,"status":200}
{"level":"debug","ts":1586267634.5913177,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:53:54 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":4.013347891,"status":200}
{"level":"debug","ts":1586267644.6206696,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.16.62:47902","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.16.62"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:54:04 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":0.922186988,"status":200}
{"level":"debug","ts":1586267644.6219041,"logger":"http.handlers.reverse_proxy","msg":"upstream roundtrip","upstream":"web:5000","request":{"method":"GET","uri":"/_health/","proto":"HTTP/1.1","remote_addr":"172.31.3.255:1646","host":"172.31.4.246","headers":{"X-Forwarded-For":["172.31.3.255"],"User-Agent":["ELB-HealthChecker/1.0"],"Accept":["*/*"]}},"headers":{"Server":["gunicorn/20.0.4"],"Date":["Tue, 07 Apr 2020 13:54:04 GMT"],"Content-Type":["text/html; charset=utf-8"]},"duration":4.044003283,"status":200}
[root@ip-172-31-4-246 ec2-user]#
5

Thanks. I’ll look more when I have a chance. Did you try @francislavoie’s suggestion?

6

Sorry for the delay. I got a drill bit stuck in my tire waiting on deploy believe it or not. Frustrating afternoon =/

[root@ip-172-31-0-243 ec2-user]# cat /var/app/current/templates/Caddyfile.json

{
    "admin": {
        "disabled": true
    },
    "apps": {
        "http": {
            "servers": {
                "srv0": {
                    "automatic_https": {
                        "disable_redirects": true
                    },
                    "listen": [
                        ":80",
                        ":443"
                    ],
                    "routes": [
                        {
                            "handle": [
                                {
                                    "handler": "subroute",
                                    "routes": [
                                        {
                                            "handle": [
                                                {
                                                    "handler": "reverse_proxy",
                                                    "upstreams": [
                                                        {
                                                            "dial": "web:5000"
                                                        }
                                                    ]
                                                }
                                            ]
                                        }
                                    ]
                                }
                            ],
                            "terminal": true
                        }
                    ],
                    "tls_connection_policies": [
                        {
                            "default_sni": "example.com"
                        }
                    ]
                }
            }
        },
        "tls": {
            "automation": {
                "policies": [
                    {
                        "issuer": {
                            "email": "foo@example.com",
                            "module": "acme"
                        },
                        "on_demand": true
                    }
                ]
            }
        }
    },
    "logging": {
        "logs": {
            "default": {
                "level": "DEBUG"
            }
        }
    }
}

Timings:

vagrant@vagrant:/vagrant$ tests/measure-http-response-time.sh 5 http://ip-172-31-0-243.ec2.internal:5000/_health/
Pass: All requests completed
Pass: No Failed Reports
Time per request: 68.725 [ms] (mean)
68.725
vagrant@vagrant:/vagrant$ tests/measure-http-response-time.sh 5 http://ip-172-31-0-243.ec2.internal/_health/
Pass: All requests completed
Pass: No Failed Reports
Time per request: 4067.568 [ms] (mean)
4067.568

I also figured I would make sure there wasn’t a networking problem between the containers:

[root@ip-172-31-0-243 ec2-user]# docker exec c473 ping -c 10 web
PING web (172.17.0.2): 56 data bytes
64 bytes from 172.17.0.2: seq=0 ttl=255 time=0.071 ms
64 bytes from 172.17.0.2: seq=1 ttl=255 time=0.074 ms
64 bytes from 172.17.0.2: seq=2 ttl=255 time=0.071 ms
64 bytes from 172.17.0.2: seq=3 ttl=255 time=0.071 ms
64 bytes from 172.17.0.2: seq=4 ttl=255 time=0.266 ms
64 bytes from 172.17.0.2: seq=5 ttl=255 time=0.078 ms
64 bytes from 172.17.0.2: seq=6 ttl=255 time=0.069 ms
64 bytes from 172.17.0.2: seq=7 ttl=255 time=0.071 ms
64 bytes from 172.17.0.2: seq=8 ttl=255 time=0.077 ms
64 bytes from 172.17.0.2: seq=9 ttl=255 time=0.074 ms

--- web ping statistics ---
10 packets transmitted, 10 packets received, 0% packet loss
round-trip min/avg/max = 0.069/0.092/0.266 ms
[root@ip-172-31-0-243 ec2-user]#

Here are the caddy logs… very long log if you want it complete and I wasn’t able to run for a delayed period after successul launch. My ip is 172.28.14.109 if you want to filter the results.

So it won’t let me post because they are too long. Log is here: https://termbin.com/mqy6

7

Thanks for the details! What are the results like if you disable logging? (Remove the whole "logging" object)

Edit: Wait, what:

Why was your tire waiting on a deploy? :face_with_raised_eyebrow: (Anyway, sorry to hear about that!)

8

Haha funny. No - probably TMI anyways. But I made a quick ride in the truck that ended up being a long ride due to drill bit from road in tire syndrome =P

I’ll try that and report back

9

Also, just to double check, 1GB memory reservation for the caddy container should be plenty right?

This is my caddy entry for the Dockerrun.aws.json file that beanstalk uses for multicontainer docker.

{
    "name": "caddy",
    "essential": true,
    "memoryReservation": 1024,
    "image": "caddy/caddy:alpine",
    "command": [
        "caddy",
        "run",
        "--config",
        "/etc/caddy/Caddyfile.json"
    ],
    "links": [
        "web"
    ],
    "mountPoints": [
        {
            "sourceVolume": "caddy_data",
            "containerPath": "/data"
        },
        {
            "sourceVolume": "caddy_file",
            "containerPath": "/etc/caddy/Caddyfile.json"
        }
    ],
    "portMappings": [
        {
            "containerPort": 80,
            "hostPort": 80,
            "protocol": "tcp"
        },
        {
            "containerPort": 443,
            "hostPort": 443,
            "protocol": "tcp"
        }
    ]
}
10

Logging probably isn’t the problem here:

vagrant@vagrant:/vagrant$ tests/measure-http-response-time.sh 5 http://ip-172-31-53-66.ec2.internal:5000/_health/
Pass: All requests completed
Pass: No Failed Reports
Time per request: 84.030 [ms] (mean)
84.030
vagrant@vagrant:/vagrant$ tests/measure-http-response-time.sh 5 http://ip-172-31-53-66.ec2.internal/_health/
Pass: All requests completed
Pass: No Failed Reports
Time per request: 3436.688 [ms] (mean)
3436.688

And here is the caddy config

[root@ip-172-31-53-66 ec2-user]# cat /var/app/current/templates/Caddyfile.json
{
    "admin": {
        "disabled": true
    },
    "apps": {
        "http": {
            "servers": {
                "srv0": {
                    "automatic_https": {
                        "disable_redirects": true
                    },
                    "listen": [
                        ":80",
                        ":443"
                    ],
                    "routes": [
                        {
                            "handle": [
                                {
                                    "handler": "subroute",
                                    "routes": [
                                        {
                                            "handle": [
                                                {
                                                    "handler": "reverse_proxy",
                                                    "upstreams": [
                                                        {
                                                            "dial": "web:5000"
                                                        }
                                                    ]
                                                }
                                            ]
                                        }
                                    ]
                                }
                            ],
                            "terminal": true
                        }
                    ],
                    "tls_connection_policies": [
                        {
                            "default_sni": "example.com"
                        }
                    ]
                }
            }
        },
        "tls": {
            "automation": {
                "policies": [
                    {
                        "issuer": {
                            "email": "foo@example.com",
                            "module": "acme"
                        },
                        "on_demand": true
                    }
                ]
            }
        }
    }
}
[root@ip-172-31-53-66 ec2-user]#
11

Hm, that’s good news in some sense I guess. It means our logging isn’t particularly inefficient.

Thanks for checking that.

Next: Let’s get a profile! After starting the server, open the admin endpoint in your browser to a special debug page: http://localhost:2019/debug/pprof/

During the load, it’d be interesting to see the heaps and goroutines. Then, capture a profile during a load, for example: http://localhost:2019/debug/pprof/profile?seconds=10

Please share your results. Bonus points if you use go tool pprof for us to see what took up the most CPU time and allocated the most memory! That will help speed up a patch.

This is an optimization so won’t necessarily block 2.0 release (I also have not experienced such slow times myself…)

12

Will give it a go. Fyi, running on t3.large ec2 instance.

AMI ID: aws-elasticbeanstalk-amzn-2018.03.20.x86_64-ecs-hvm-202002212029 (ami-05470ed7d1a846f4f)

EB_PLATFORM: ‘64bit Amazon Linux 2018.03 v2.19.1 running Multi-container Docker 18.09.9-ce (Generic)’

As far as I know these are the newest versions available

13

Heap

heap profile: 0: 0 [6: 78016] @ heap/1048576
0: 0 [0: 0] @ 0x787ba3 0x787ad4 0x7848ca 0x791eda 0x792935 0x708124 0x709f65 0x8cdad1 0x8cd986 0x70b4b3 0x706f2c 0x4670b1
#	0x787ba2	runtime/pprof.writeGoroutineStacks+0x42				runtime/pprof/pprof.go:663
#	0x787ad3	runtime/pprof.writeGoroutine+0x43				runtime/pprof/pprof.go:654
#	0x7848c9	runtime/pprof.(*Profile).WriteTo+0x3d9				runtime/pprof/pprof.go:329
#	0x791ed9	net/http/pprof.handler.ServeHTTP+0x339				net/http/pprof/pprof.go:248
#	0x792934	net/http/pprof.Index+0x734					net/http/pprof/pprof.go:271
#	0x708123	net/http.HandlerFunc.ServeHTTP+0x43				net/http/server.go:2012
#	0x709f64	net/http.(*ServeMux).ServeHTTP+0x1a4				net/http/server.go:2387
#	0x8cdad0	github.com/caddyserver/caddy/v2.adminHandler.serveHTTP+0x70	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/admin.go:302
#	0x8cd985	github.com/caddyserver/caddy/v2.adminHandler.ServeHTTP+0x4f5	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/admin.go:270
#	0x70b4b2	net/http.serverHandler.ServeHTTP+0xa2				net/http/server.go:2807
#	0x706f2b	net/http.(*conn).serve+0x86b					net/http/server.go:1895

0: 0 [0: 0] @ 0x78611a 0x786044 0x7848ca 0x791eda 0x792935 0x708124 0x709f65 0x8cdad1 0x8cd986 0x70b4b3 0x706f2c 0x4670b1
#	0x786119	runtime/pprof.writeHeapInternal+0xa9				runtime/pprof/pprof.go:549
#	0x786043	runtime/pprof.writeAlloc+0x53					runtime/pprof/pprof.go:525
#	0x7848c9	runtime/pprof.(*Profile).WriteTo+0x3d9				runtime/pprof/pprof.go:329
#	0x791ed9	net/http/pprof.handler.ServeHTTP+0x339				net/http/pprof/pprof.go:248
#	0x792934	net/http/pprof.Index+0x734					net/http/pprof/pprof.go:271
#	0x708123	net/http.HandlerFunc.ServeHTTP+0x43				net/http/server.go:2012
#	0x709f64	net/http.(*ServeMux).ServeHTTP+0x1a4				net/http/server.go:2387
#	0x8cdad0	github.com/caddyserver/caddy/v2.adminHandler.serveHTTP+0x70	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/admin.go:302
#	0x8cd985	github.com/caddyserver/caddy/v2.adminHandler.ServeHTTP+0x4f5	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/admin.go:270
#	0x70b4b2	net/http.serverHandler.ServeHTTP+0xa2				net/http/server.go:2807
#	0x706f2b	net/http.(*conn).serve+0x86b					net/http/server.go:1895

0: 0 [0: 0] @ 0x56d170 0x56db63 0x568963 0x57e429 0x57f357 0x58066c 0x5aa721 0x4670b1
#	0x56d16f	vendor/golang.org/x/net/dns/dnsmessage.(*Name).pack+0x3df	vendor/golang.org/x/net/dns/dnsmessage/message.go:1952
#	0x56db62	vendor/golang.org/x/net/dns/dnsmessage.(*Question).pack+0x82	vendor/golang.org/x/net/dns/dnsmessage/message.go:2084
#	0x568962	vendor/golang.org/x/net/dns/dnsmessage.(*Builder).Question+0x72	vendor/golang.org/x/net/dns/dnsmessage/message.go:1299
#	0x57e428	net.newRequest+0x1f8						net/dnsclient_unix.go:56
#	0x57f356	net.(*Resolver).exchange+0xb6					net/dnsclient_unix.go:142
#	0x58066b	net.(*Resolver).tryOneName+0x32b				net/dnsclient_unix.go:256
#	0x5aa720	net.(*Resolver).goLookupIPCNAMEOrder.func3.1+0x90		net/dnsclient_unix.go:602

0: 0 [0: 0] @ 0x594e6c 0x592caa 0x57935e 0x57a5ca 0x123fc1b 0x71c105 0x71ffce 0x71d996 0x4670b1
#	0x594e6b	net.(*Resolver).lookupIPAddr+0x4cb									net/lookup.go:266
#	0x592ca9	net.(*Resolver).internetAddrList+0x4d9									net/ipsock.go:280
#	0x57935d	net.(*Resolver).resolveAddrList+0x49d									net/dial.go:222
#	0x57a5c9	net.(*Dialer).DialContext+0x229										net/dial.go:404
#	0x123fc1a	github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy.(*HTTPTransport).newTransport.func1+0xfa	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/reverseproxy/httptransport.go:99
#	0x71c104	net/http.(*Transport).dial+0x1f4									net/http/transport.go:1085
#	0x71ffcd	net/http.(*Transport).dialConn+0x19ed									net/http/transport.go:1519
#	0x71d995	net/http.(*Transport).dialConnFor+0xc5									net/http/transport.go:1365

0: 0 [0: 0] @ 0x582ba0 0x596751 0x5a9cf2 0x5ab1a9 0x5757ce 0x4670b1
#	0x582b9f	net.(*Resolver).goLookupIPCNAMEOrder+0x12f	net/dnsclient_unix.go:586
#	0x596750	net.(*Resolver).lookupIP+0xe0			net/lookup_unix.go:102
#	0x5a9cf1	net.glob..func1+0x71				net/hook.go:23
#	0x5ab1a8	net.(*Resolver).lookupIPAddr.func1+0xb8		net/lookup.go:268
#	0x5757cd	internal/singleflight.(*Group).doCall+0x2d	internal/singleflight/singleflight.go:95

0: 0 [1: 32768] @ 0x123d472 0x123d022 0x123a800 0x1238a76 0xea9bcf 0xe97334 0xea9891 0xe97334 0xea35cb 0xeaa79a 0xe97334 0xea259d 0x70b4b3 0x706f2c 0x4670b1
#	0x123d471	github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy.Handler.copyBuffer+0x2d1		github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/reverseproxy/streaming.go:121
#	0x123d021	github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy.Handler.copyResponse+0xf1	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/reverseproxy/streaming.go:113
#	0x123a7ff	github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy.(*Handler).reverseProxy+0xf8f	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/reverseproxy/reverseproxy.go:521
#	0x1238a75	github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy.(*Handler).ServeHTTP+0xc75	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/reverseproxy/reverseproxy.go:346
#	0xea9bce	github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1+0x5e			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/routes.go:256
#	0xe97333	github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP+0x43			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/caddyhttp.go:61
#	0xea9890	github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapRoute.func1.1+0x120			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/routes.go:231
#	0xe97333	github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP+0x43			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/caddyhttp.go:61
#	0xea35ca	github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).enforcementHandler+0x9a		github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/server.go:273
#	0xeaa799	github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).wrapPrimaryRoute.func1+0x59		github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/server.go:249
#	0xe97333	github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP+0x43			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/caddyhttp.go:61
#	0xea259c	github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).ServeHTTP+0x85c			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/server.go:204
#	0x70b4b2	net/http.serverHandler.ServeHTTP+0xa2								net/http/server.go:2807
#	0x706f2b	net/http.(*conn).serve+0x86b									net/http/server.go:1895

0: 0 [1: 80] @ 0x5755ca 0x594f20 0x592caa 0x57935e 0x57a5ca 0x123fc1b 0x71c105 0x71ffce 0x71d996 0x4670b1
#	0x5755c9	internal/singleflight.(*Group).DoChan+0x1a9								internal/singleflight/singleflight.go:83
#	0x594f1f	net.(*Resolver).lookupIPAddr+0x57f									net/lookup.go:266
#	0x592ca9	net.(*Resolver).internetAddrList+0x4d9									net/ipsock.go:280
#	0x57935d	net.(*Resolver).resolveAddrList+0x49d									net/dial.go:222
#	0x57a5c9	net.(*Dialer).DialContext+0x229										net/dial.go:404
#	0x123fc1a	github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy.(*HTTPTransport).newTransport.func1+0xfa	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/reverseproxy/httptransport.go:99
#	0x71c104	net/http.(*Transport).dial+0x1f4									net/http/transport.go:1085
#	0x71ffcd	net/http.(*Transport).dialConn+0x19ed									net/http/transport.go:1519
#	0x71d995	net/http.(*Transport).dialConnFor+0xc5									net/http/transport.go:1365

0: 0 [1: 8192] @ 0x4aaa73 0x55c81b 0x55c6ff 0x55c182 0x55c40f 0x55c66f 0x8b621d 0x8bfc4d 0x8bf663 0xc48d83 0xc48c0f 0xc47d92 0x8e46ea 0x8d4a02 0x8d3d87 0x8d301b 0x8f571d 0x8f5ce9 0x8fb0ee 0x128b5c0 0x436ef2 0x4670b1
#	0x4aaa72	os.(*File).readdirnames+0x3e2							os/dir_unix.go:36
#	0x55c81a	os.(*File).Readdirnames+0x18a							os/dir.go:48
#	0x55c6fe	path/filepath.readDirNames+0x6e							path/filepath/path.go:421
#	0x55c181	path/filepath.walk+0x71								path/filepath/path.go:363
#	0x55c40e	path/filepath.walk+0x2fe							path/filepath/path.go:384
#	0x55c66e	path/filepath.Walk+0xfe								path/filepath/path.go:406
#	0x8b621c	github.com/caddyserver/certmagic.(*FileStorage).List+0x12c			github.com/caddyserver/certmagic@v0.10.7/filestorage.go:76
#	0x8bfc4c	github.com/caddyserver/certmagic.deleteExpiredCerts+0xec			github.com/caddyserver/certmagic@v0.10.7/maintain.go:397
#	0x8bf662	github.com/caddyserver/certmagic.CleanStorage+0x62				github.com/caddyserver/certmagic@v0.10.7/maintain.go:349
#	0xc48d82	github.com/caddyserver/caddy/v2/modules/caddytls.(*TLS).cleanStorageUnits+0x132	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddytls/tls.go:375
#	0xc48c0e	github.com/caddyserver/caddy/v2/modules/caddytls.(*TLS).keepStorageClean+0xae	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddytls/tls.go:357
#	0xc47d91	github.com/caddyserver/caddy/v2/modules/caddytls.(*TLS).Start+0x131		github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddytls/tls.go:213
#	0x8e46e9	github.com/caddyserver/caddy/v2.run.func4+0xf9					github.com/caddyserver/caddy/v2@v2.0.0-rc.1/caddy.go:406
#	0x8d4a01	github.com/caddyserver/caddy/v2.run+0x2c1					github.com/caddyserver/caddy/v2@v2.0.0-rc.1/caddy.go:422
#	0x8d3d86	github.com/caddyserver/caddy/v2.unsyncedDecodeAndRun+0xf6			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/caddy.go:249
#	0x8d301a	github.com/caddyserver/caddy/v2.changeConfig+0x4ba				github.com/caddyserver/caddy/v2@v2.0.0-rc.1/caddy.go:156
#	0x8f571c	github.com/caddyserver/caddy/v2.Load+0x2ac					github.com/caddyserver/caddy/v2@v2.0.0-rc.1/caddy.go:102
#	0x8f5ce8	github.com/caddyserver/caddy/v2/cmd.cmdRun+0x878				github.com/caddyserver/caddy/v2@v2.0.0-rc.1/cmd/commandfuncs.go:187
#	0x8fb0ed	github.com/caddyserver/caddy/v2/cmd.Main+0x23d					github.com/caddyserver/caddy/v2@v2.0.0-rc.1/cmd/main.go:84
#	0x128b5bf	main.main+0x1f									command-line-arguments/main.go:37
#	0x436ef1	runtime.main+0x211								runtime/proc.go:203

0: 0 [1: 4096] @ 0x79dcef 0x79e38d 0x79c8ff 0x79d239 0x799daa 0x7ac39a 0x7ad14b 0x7ad122 0xbdc25a 0x443ada 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x436eae 0x4670b1
#	0x79dcee	regexp/syntax.appendRange+0x10e			regexp/syntax/parse.go:1688
#	0x79e38c	regexp/syntax.appendTable+0x7c			regexp/syntax/parse.go:1776
#	0x79c8fe	regexp/syntax.(*parser).parseUnicodeClass+0x20e	regexp/syntax/parse.go:1508
#	0x79d238	regexp/syntax.(*parser).parseClass+0x248	regexp/syntax/parse.go:1574
#	0x799da9	regexp/syntax.Parse+0xc99			regexp/syntax/parse.go:774
#	0x7ac399	regexp.compile+0x59				regexp/regexp.go:170
#	0x7ad14a	regexp.Compile+0x4a				regexp/regexp.go:133
#	0x7ad121	regexp.MustCompile+0x21				regexp/regexp.go:309
#	0xbdc259	github.com/google/go-cmp/cmp.init+0x39		github.com/google/go-cmp@v0.4.0/cmp/options.go:250
#	0x443ad9	runtime.doInit+0x89				runtime/proc.go:5414
#	0x443aa6	runtime.doInit+0x56				runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56				runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56				runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56				runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56				runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56				runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56				runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56				runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56				runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56				runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56				runtime/proc.go:5409
#	0x436ead	runtime.main+0x1cd				runtime/proc.go:190

0: 0 [1: 112] @ 0x7a48da 0x7a4890 0x7a3e3b 0x7a3e3b 0x7a3e3b 0x7ac404 0x7ad14b 0x7ad122 0xbafa06 0x443ada 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x436eae 0x4670b1
#	0x7a48d9	regexp/syntax.simplify1+0xb59		regexp/syntax/simplify.go:148
#	0x7a488f	regexp/syntax.(*Regexp).Simplify+0xb0f	regexp/syntax/simplify.go:100
#	0x7a3e3a	regexp/syntax.(*Regexp).Simplify+0xba	regexp/syntax/simplify.go:23
#	0x7a3e3a	regexp/syntax.(*Regexp).Simplify+0xba	regexp/syntax/simplify.go:23
#	0x7a3e3a	regexp/syntax.(*Regexp).Simplify+0xba	regexp/syntax/simplify.go:23
#	0x7ac403	regexp.compile+0xc3			regexp/regexp.go:177
#	0x7ad14a	regexp.Compile+0x4a			regexp/regexp.go:133
#	0x7ad121	regexp.MustCompile+0x21			regexp/regexp.go:309
#	0xbafa05	go.opencensus.io/resource.init+0x35	go.opencensus.io@v0.22.3/resource/resource.go:60
#	0x443ad9	runtime.doInit+0x89			runtime/proc.go:5414
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56			runtime/proc.go:5409
#	0x436ead	runtime.main+0x1cd			runtime/proc.go:190

0: 0 [1: 32768] @ 0x7a6b31 0x7a7a96 0x7aa423 0x8fabb1 0x8fab75 0x8fab5e 0x9cbc54 0x443ada 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x443aa7 0x436eae 0x4670b1
#	0x7a6b30	regexp.(*bitState).reset+0x200					regexp/backtrack.go:91
#	0x7a7a95	regexp.(*Regexp).backtrack+0x115				regexp/backtrack.go:319
#	0x7aa422	regexp.(*Regexp).doExecute+0x452				regexp/exec.go:535
#	0x8fabb0	regexp.(*Regexp).doMatch+0xf0					regexp/exec.go:514
#	0x8fab74	regexp.(*Regexp).MatchString+0xb4				regexp/regexp.go:507
#	0x8fab5d	github.com/caddyserver/caddy/v2/cmd.RegisterCommand+0x9d	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/cmd/commands.go:298
#	0x9cbc53	github.com/caddyserver/caddy/v2/modules/caddypki.init.0+0xd3	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddypki/command.go:30
#	0x443ad9	runtime.doInit+0x89						runtime/proc.go:5414
#	0x443aa6	runtime.doInit+0x56						runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56						runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56						runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56						runtime/proc.go:5409
#	0x443aa6	runtime.doInit+0x56						runtime/proc.go:5409
#	0x436ead	runtime.main+0x1cd						runtime/proc.go:190


# runtime.MemStats
# Alloc = 5383544
# TotalAlloc = 13721184
# Sys = 72958208
# Lookups = 0
# Mallocs = 82867
# Frees = 50664
# HeapAlloc = 5383544
# HeapSys = 66420736
# HeapIdle = 58736640
# HeapInuse = 7684096
# HeapReleased = 57507840
# HeapObjects = 32203
# Stack = 688128 / 688128
# MSpan = 93568 / 114688
# MCache = 3472 / 16384
# BuckHashSys = 1449052
# GCSys = 3582216
# OtherSys = 687004
# NextGC = 7128816
# LastGC = 1586291043012352243
# PauseNs = [1024918 24157 31006 36768 47703 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]
# PauseEnd = [1586290763722995723 1586290763733617978 1586290795291912075 1586290921284358813 1586291043012352243 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0]
# NumGC = 5
# NumForcedGC = 0
# GCCPUFraction = 1.7401126533522716e-05
# DebugGC = false
14

goroutine

goroutine profile: total 22
3 @ 0x4372d0 0x43023a 0x42f7a5 0x4a45f5 0x4a548b 0x4a546d 0x58670f 0x598ffe 0x701108 0x4670b1
#	0x42f7a4	internal/poll.runtime_pollWait+0x54		runtime/netpoll.go:203
#	0x4a45f4	internal/poll.(*pollDesc).wait+0x44		internal/poll/fd_poll_runtime.go:87
#	0x4a548a	internal/poll.(*pollDesc).waitRead+0x19a	internal/poll/fd_poll_runtime.go:92
#	0x4a546c	internal/poll.(*FD).Read+0x17c			internal/poll/fd_unix.go:169
#	0x58670e	net.(*netFD).Read+0x4e				net/fd_unix.go:202
#	0x598ffd	net.(*conn).Read+0x8d				net/net.go:184
#	0x701107	net/http.(*connReader).backgroundRead+0x57	net/http/server.go:678

2 @ 0x4372d0 0x43023a 0x42f7a5 0x4a45f5 0x4a548b 0x4a546d 0x58670f 0x598ffe 0x57e882 0x57f720 0x58066c 0x5aa721 0x4670b1
#	0x42f7a4	internal/poll.runtime_pollWait+0x54			runtime/netpoll.go:203
#	0x4a45f4	internal/poll.(*pollDesc).wait+0x44			internal/poll/fd_poll_runtime.go:87
#	0x4a548a	internal/poll.(*pollDesc).waitRead+0x19a		internal/poll/fd_poll_runtime.go:92
#	0x4a546c	internal/poll.(*FD).Read+0x17c				internal/poll/fd_unix.go:169
#	0x58670e	net.(*netFD).Read+0x4e					net/fd_unix.go:202
#	0x598ffd	net.(*conn).Read+0x8d					net/net.go:184
#	0x57e881	net.dnsPacketRoundTrip+0x131				net/dnsclient_unix.go:87
#	0x57f71f	net.(*Resolver).exchange+0x47f				net/dnsclient_unix.go:166
#	0x58066b	net.(*Resolver).tryOneName+0x32b			net/dnsclient_unix.go:256
#	0x5aa720	net.(*Resolver).goLookupIPCNAMEOrder.func3.1+0x90	net/dnsclient_unix.go:602

2 @ 0x4372d0 0x43023a 0x42f7a5 0x4a45f5 0x4a6e34 0x4a6e16 0x586fc2 0x5a2e32 0x5a1bc4 0x8d9383 0x70b85d 0x4670b1
#	0x42f7a4	internal/poll.runtime_pollWait+0x54					runtime/netpoll.go:203
#	0x4a45f4	internal/poll.(*pollDesc).wait+0x44					internal/poll/fd_poll_runtime.go:87
#	0x4a6e33	internal/poll.(*pollDesc).waitRead+0x1d3				internal/poll/fd_poll_runtime.go:92
#	0x4a6e15	internal/poll.(*FD).Accept+0x1b5					internal/poll/fd_unix.go:384
#	0x586fc1	net.(*netFD).accept+0x41						net/fd_unix.go:238
#	0x5a2e31	net.(*TCPListener).accept+0x31						net/tcpsock_posix.go:139
#	0x5a1bc3	net.(*TCPListener).Accept+0x63						net/tcpsock.go:261
#	0x8d9382	github.com/caddyserver/caddy/v2.(*fakeCloseListener).Accept+0x42	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/listeners.go:121
#	0x70b85c	net/http.(*Server).Serve+0x25c						net/http/server.go:2901

2 @ 0x4372d0 0x4474e3 0x595004 0x592caa 0x57935e 0x57a5ca 0x123fc1b 0x71c105 0x71ffce 0x71d996 0x4670b1
#	0x595003	net.(*Resolver).lookupIPAddr+0x663									net/lookup.go:274
#	0x592ca9	net.(*Resolver).internetAddrList+0x4d9									net/ipsock.go:280
#	0x57935d	net.(*Resolver).resolveAddrList+0x49d									net/dial.go:222
#	0x57a5c9	net.(*Dialer).DialContext+0x229										net/dial.go:404
#	0x123fc1a	github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy.(*HTTPTransport).newTransport.func1+0xfa	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/reverseproxy/httptransport.go:99
#	0x71c104	net/http.(*Transport).dial+0x1f4									net/http/transport.go:1085
#	0x71ffcd	net/http.(*Transport).dialConn+0x19ed									net/http/transport.go:1519
#	0x71d995	net/http.(*Transport).dialConnFor+0xc5									net/http/transport.go:1365

2 @ 0x4372d0 0x4474e3 0x71cd3b 0x7189c6 0x12356cd 0x12356bc 0x1239a5c 0x1238a76 0xea9bcf 0xe97334 0xea9891 0xe97334 0xea35cb 0xeaa79a 0xe97334 0xea259d 0x70b4b3 0x706f2c 0x4670b1
#	0x71cd3a	net/http.(*Transport).getConn+0x57a								net/http/transport.go:1291
#	0x7189c5	net/http.(*Transport).roundTrip+0x725								net/http/transport.go:552
#	0x12356cc	net/http.(*Transport).RoundTrip+0x8c								net/http/roundtrip.go:17
#	0x12356bb	github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy.(*HTTPTransport).RoundTrip+0x7b	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/reverseproxy/httptransport.go:152
#	0x1239a5b	github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy.(*Handler).reverseProxy+0x1eb	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/reverseproxy/reverseproxy.go:441
#	0x1238a75	github.com/caddyserver/caddy/v2/modules/caddyhttp/reverseproxy.(*Handler).ServeHTTP+0xc75	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/reverseproxy/reverseproxy.go:346
#	0xea9bce	github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1+0x5e			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/routes.go:256
#	0xe97333	github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP+0x43			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/caddyhttp.go:61
#	0xea9890	github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapRoute.func1.1+0x120			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/routes.go:231
#	0xe97333	github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP+0x43			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/caddyhttp.go:61
#	0xea35ca	github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).enforcementHandler+0x9a		github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/server.go:273
#	0xeaa799	github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).wrapPrimaryRoute.func1+0x59		github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/server.go:249
#	0xe97333	github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP+0x43			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/caddyhttp.go:61
#	0xea259c	github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).ServeHTTP+0x85c			github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddyhttp/server.go:204
#	0x70b4b2	net/http.serverHandler.ServeHTTP+0xa2								net/http/server.go:2807
#	0x706f2b	net/http.(*conn).serve+0x86b									net/http/server.go:1895

1 @ 0x40b4b4 0x44c18c 0x8cbc22 0x4670b1
#	0x44c18b	os/signal.signal_recv+0x9b	runtime/sigqueue.go:147
#	0x8cbc21	os/signal.loop+0x21		os/signal/signal_unix.go:23

1 @ 0x4372d0 0x405ec7 0x405b8b 0x5aa9cc 0x5831d8 0x596751 0x5a9cf2 0x5ab1a9 0x5757ce 0x4670b1
#	0x5aa9cb	net.(*Resolver).goLookupIPCNAMEOrder.func4+0x9b	net/dnsclient_unix.go:608
#	0x5831d7	net.(*Resolver).goLookupIPCNAMEOrder+0x767	net/dnsclient_unix.go:618
#	0x596750	net.(*Resolver).lookupIP+0xe0			net/lookup_unix.go:102
#	0x5a9cf1	net.glob..func1+0x71				net/hook.go:23
#	0x5ab1a8	net.(*Resolver).lookupIPAddr.func1+0xb8		net/lookup.go:268
#	0x5757cd	internal/singleflight.(*Group).doCall+0x2d	internal/singleflight/singleflight.go:95

1 @ 0x4372d0 0x405ec7 0x405b8b 0x8e5389 0x4670b1
#	0x8e5388	github.com/caddyserver/caddy/v2.trapSignalsCrossPlatform.func1+0x128	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/sigtrap.go:42

1 @ 0x4372d0 0x405ec7 0x405bcb 0x8e57b9 0x4670b1
#	0x8e57b8	github.com/caddyserver/caddy/v2.trapSignalsPosix.func1+0x138	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/sigtrap_posix.go:34

1 @ 0x4372d0 0x43023a 0x42f7a5 0x4a45f5 0x4a6e34 0x4a6e16 0x586fc2 0x5a2e32 0x5a1bc4 0x8d9383 0x66d5f7 0x70b85d 0x4670b1
#	0x42f7a4	internal/poll.runtime_pollWait+0x54					runtime/netpoll.go:203
#	0x4a45f4	internal/poll.(*pollDesc).wait+0x44					internal/poll/fd_poll_runtime.go:87
#	0x4a6e33	internal/poll.(*pollDesc).waitRead+0x1d3				internal/poll/fd_poll_runtime.go:92
#	0x4a6e15	internal/poll.(*FD).Accept+0x1b5					internal/poll/fd_unix.go:384
#	0x586fc1	net.(*netFD).accept+0x41						net/fd_unix.go:238
#	0x5a2e31	net.(*TCPListener).accept+0x31						net/tcpsock_posix.go:139
#	0x5a1bc3	net.(*TCPListener).Accept+0x63						net/tcpsock.go:261
#	0x8d9382	github.com/caddyserver/caddy/v2.(*fakeCloseListener).Accept+0x42	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/listeners.go:121
#	0x66d5f6	crypto/tls.(*listener).Accept+0x36					crypto/tls/tls.go:55
#	0x70b85c	net/http.(*Server).Serve+0x25c						net/http/server.go:2901

1 @ 0x4372d0 0x446859 0x8f6157 0x8fb0ee 0x128b5c0 0x436ef2 0x4670b1
#	0x8f6156	github.com/caddyserver/caddy/v2/cmd.cmdRun+0xce6	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/cmd/commandfuncs.go:239
#	0x8fb0ed	github.com/caddyserver/caddy/v2/cmd.Main+0x23d		github.com/caddyserver/caddy/v2@v2.0.0-rc.1/cmd/main.go:84
#	0x128b5bf	main.main+0x1f						command-line-arguments/main.go:37
#	0x436ef1	runtime.main+0x211					runtime/proc.go:203

1 @ 0x4372d0 0x4474e3 0x8bc7b2 0x4670b1
#	0x8bc7b1	github.com/caddyserver/certmagic.(*Cache).maintainAssets+0x1d1	github.com/caddyserver/certmagic@v0.10.7/maintain.go:45

1 @ 0x4372d0 0x4474e3 0x8c2d21 0x8c238a 0x4670b1
#	0x8c2d20	github.com/caddyserver/certmagic.(*RingBufferRateLimiter).permit+0xe0	github.com/caddyserver/certmagic@v0.10.7/ratelimiter.go:192
#	0x8c2389	github.com/caddyserver/certmagic.(*RingBufferRateLimiter).loop+0x79	github.com/caddyserver/certmagic@v0.10.7/ratelimiter.go:65

1 @ 0x4372d0 0x4474e3 0xbb6300 0x4670b1
#	0xbb62ff	go.opencensus.io/stats/view.(*worker).start+0xff	go.opencensus.io@v0.22.3/stats/view/worker.go:154

1 @ 0x4372d0 0x4474e3 0xc4c20c 0x4670b1
#	0xc4c20b	github.com/caddyserver/caddy/v2/modules/caddytls.(*TLS).keepStorageClean.func1+0xbb	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/modules/caddytls/tls.go:349

1 @ 0x787d15 0x787b30 0x7848ca 0x791eda 0x792935 0x708124 0x709f65 0x8cdad1 0x8cd986 0x70b4b3 0x706f2c 0x4670b1
#	0x787d14	runtime/pprof.writeRuntimeProfile+0x94				runtime/pprof/pprof.go:694
#	0x787b2f	runtime/pprof.writeGoroutine+0x9f				runtime/pprof/pprof.go:656
#	0x7848c9	runtime/pprof.(*Profile).WriteTo+0x3d9				runtime/pprof/pprof.go:329
#	0x791ed9	net/http/pprof.handler.ServeHTTP+0x339				net/http/pprof/pprof.go:248
#	0x792934	net/http/pprof.Index+0x734					net/http/pprof/pprof.go:271
#	0x708123	net/http.HandlerFunc.ServeHTTP+0x43				net/http/server.go:2012
#	0x709f64	net/http.(*ServeMux).ServeHTTP+0x1a4				net/http/server.go:2387
#	0x8cdad0	github.com/caddyserver/caddy/v2.adminHandler.serveHTTP+0x70	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/admin.go:302
#	0x8cd985	github.com/caddyserver/caddy/v2.adminHandler.ServeHTTP+0x4f5	github.com/caddyserver/caddy/v2@v2.0.0-rc.1/admin.go:270
#	0x70b4b2	net/http.serverHandler.ServeHTTP+0xa2				net/http/server.go:2807
#	0x706f2b	net/http.(*conn).serve+0x86b					net/http/server.go:1895
15

I don’t seem to have an option to attach the file downloaded from the profile. Not sure how to inspect it. I don’t speak go =(

Profile is available here: Slow response using reverse proxy · Issue #3238 · caddyserver/caddy · GitHub

16

Here is the caddy config used during the profile

[root@ip-172-31-23-203 ec2-user]# cat /var/app/current/templates/Caddyfile.json
{
"admin": {
    "listen": ":2019"
},
"apps": {
    "http": {
        "servers": {
            "srv0": {
                "automatic_https": {
                    "disable_redirects": true
                },
                "listen": [
                    ":80",
                    ":443"
                ],
                "routes": [
                    {
                        "handle": [
                            {
                                "handler": "reverse_proxy",
                                "upstreams": [
                                    {
                                        "dial": "web:5000"
                                    }
                                ]
                            }
                        ],
                        "terminal": true
                    }
                ],
                "tls_connection_policies": [
                    {
                        "default_sni": "example.com"
                    }
                ]
            }
        }
    },
    "tls": {
        "automation": {
            "policies": [
                {
                    "issuer": {
                        "email": "foo@example.com",
                        "module": "acme"
                    },
                    "on_demand": true
                }
            ]
        }
    }
}
}
17

Thanks!

But, are you sure you captured these during a load test? All these diagnostics are indicative of an idle server.

18

No it wasn’t a load test. All of these have been concurrency 1 sequential requests. That’s why the slow response time is confusing. There is basically no load

19

[quote="gord

Huh? But that’s inconsistent with everything you wrote above:

I suppose if we are to look into this further, we’ll need to be able to replicate your exact environment.

20

I will put together a reproducible example tomorrow if you would like to upload it to your own vpc.