Php fastcgi i/o timeout and too many open files

1. Caddy version (caddy version):

v2.0

2. How I run Caddy:

sudo caddy --config caddy.json

a. System environment:

ubuntu 18.04

b. Command:

sudo caddy run --config caddy.json

c. Service/unit/compose file:

d. My complete Caddyfile or JSON config:

{
  "logging": {
    "logs": {
      "default": {
        "exclude": [
          "http.log.access.log0"
        ]
      },
      "log0": {
        "writer": {
          "filename": "access_dom1.log",
          "output": "file"
        },
        "encoder": {
          "field": "common_log",
          "format": "single_field"
        },
        "include": [
          "http.log.access.log0"
        ]
      }
    }
  },
  "apps": {
    "http": {
      "servers": {
        "srv0": {
          "listen": [
            ":443"
          ],
          "idle_timeout": "200ms",
          "routes": [
            {
              "match": [
                {
                  "host": [
                    "example.net"
                  ]
                }
              ],
              "handle": [
                {
                  "handler": "subroute",
                  "routes": [
                    {
                      "handle": [
                        {
                          "handler": "vars",
                          "root": "/var/www/bench/bench/public"
                        }
                      ]
                    },
                    {
                      "handle": [
                        {
                          "handler": "static_response",
                          "headers": {
                            "Location": [
                              "{http.request.uri.path}/"
                            ]
                          },
                                                      "status_code": 308
                        }
                      ],
                      "match": [
                        {
                          "file": {
                            "try_files": [
                              "{http.request.uri.path}/index.php"
                            ]
                          },
                          "not": [
                            {
                              "path": [
                                "*/"
                              ]
                            }
                          ]
                        }
                      ]
                    },
                    {
                      "group": "group0",
                      "handle": [
                        {
                          "handler": "rewrite",
                          "uri": "{http.matchers.file.relative}"
                        }
                      ],
                      "match": [
                        {
                          "file": {
                            "try_files": [
                              "{http.request.uri.path}",
                              "{http.request.uri.path}/index.php",
                              "index.php"
                            ]
                          }
                        }
                      ]
                    },
                    {
                      "handle": [
                        {
                          "encodings": {
                            "gzip": {},
                            "zstd": {}
                          },
                          "handler": "encode"
                        }
                      ]
                    },
                    {
                      "handle": [
                        {
                          "handler": "reverse_proxy",
                          "transport": {
                            "protocol": "fastcgi",
                            "split_path": [
                              ".php"
                            ],
                            "read_timeout": "300ms",
                         "write_timeout": "300ms"
                          },
                          "upstreams": [
                            {
                              "dial": "unix//run/php/php7.3-fpm.sock"
                            }
                          ]
                        }
                      ],
                      "match": [
                        {
                          "path": [
                            "*.php"
                          ]
                        }
                      ]
                    }
                  ]
                }
              ],
              "terminal": true
            }
          ],
          "logs": {
            "logger_names": {
              "example.net": "log0"
            }
          }
        }
      }
    }
  }
}

3. The problem I’m having:

I’ve gotten everything set up to mostly resemble my nginx conf. I’m trying to do some load testing between nginx and caddy. I’m using locust for testing, nginx is able to get to 135 RPS (requests per second) with no issue. Caddy can get to about 55 RPS before throwing read unix @->/run/php/php7.3-fpm.sock: i/o timeout.

I’m assuming this is because of the timeout I set.
before i set the time out i was getting the error read unix @->/run/php/php7.3-fpm.sock: too many open files

When i do lsof | grep -e caddy i get hundreds (up to the limit i set for php) of

caddy     17476 17724             root 1011u     IPv6           13599486        0t0        TCP xxx.xxx.xxx.xx:https->xx-xxx-xxx-xxx-static.hfc.comcastbusiness.net:61893 (ESTABLISHED)

From what i’ve seen other users post caddy vs nginx shows they are fairly similar. If i can get this figured out this will be my final question :laughing:

4. Error messages and/or full log output:


2020/05/20 16:26:38.902 ERROR   http.log.error.log0     dialing backend: dial unix /run/php/php7.3-fpm.sock: socket: too many open files     {"request": {"method": "GET", "uri": "/", "proto": "HTTP/1.1", "remote_addr": "xxx.x.xxx.xx:55557", "host": "example.net", "headers": {"User-Agent": ["python-requests/2.23.0"], "Accept-Encoding": ["gzip, deflate"], "Accept": ["*/*"], "Connection": ["keep-alive"], "Cookie": ["XSRF-TOKEN=eyJpdiI6InVLUkFWV1VYZ1NLQW5oVHhEZXdCQ1E9PSIsInZhbHVlIjoianp1NzQzT21ZODRYZjVnbEkwalBRTVNQKzhrZTNDVEdKL3FPYXB5bDAvRXZrSDloSGk5dWNQTEFxS295QVFibSIsIm1hYyI6ImY4ODliYTIyNjg3MTRlODA5MmZhOWE2MjVhNThkYWUyYTFkNjM3ODhlNTVjMDFlNmZhOGRjZjZmYTYzMmRjZTMifQ%3D%3D; laravel_session=eyJpdiI6IjI4UzltdzN1ZVRPcEZHZnpUTUhYN1E9PSIsInZhbHVlIjoibDVJU2xpQlJzTXlBaEVqRmNXM1VtNWlOcUNobFc3Yk9nVUN6bHYzMEErYkZ0b3dzbDFQU2d4K3g1eHpJdjdSMCIsIm1hYyI6IjhiNTRkYThmYzZkYWM0ODExYzQ5OWNjMDgzZWYzMWZjY2VjYTlmODRkZjlkOWViMGY0N2IzNDVjYjgwNjY5N2YifQ%3D%3D"]}, "tls": {"resumed": false, "version": 772, "ciphersuite": 4865, "proto": "", "proto_mutual": true, "server_name": "example.net"}}, "duration": 0.001816113, "status": 502, "err_id": "69thix4hx", "err_trace": "reverseproxy.(*Handler).ServeHTTP (reverseproxy.go:380)"}

http.log.error.log0 read unix @->/run/php/php7.3-fpm.sock: i/o timeout {"request": {"method": "GET", "uri": "//", "proto": "HTTP/1.1", "remote_addr": "xx.xxx.xxx.xxx:52682", "host": "example.net", "headers": {"User-Agent": ["python-requests/2.23.0"], "Accept-Encoding": ["gzip, deflate"], "Accept": ["*/*"], "Connection": ["keep-alive"]}, "tls": {"resumed": false, "version": 772, "ciphersuite": 4865, "proto": "", "proto_mutual": true, "server_name": "example.net"}}, "duration": 0.300784001, "status": 502, "err_id": "r5sbn4tqe", "err_trace": "reverseproxy.(*Handler).ServeHTTP (reverseproxy.go:380)"}

5. What I already tried:

6. Links to relevant resources:

Is the system and php-fpm configured exactly the same when comparing Caddy and Nginx? Seems like the error is coming from php-fpm.

Are those logs from Caddy itself? I’ve not seen those before (I don’t see read unix in the Caddy codebase). Do the Caddy logs have anything relevant?

both nginx and caddy are running the same php-fpm. Both are installed on the same system to ensure any tweaking we did to php is the same for both web servers.

I’ve updated the error logs in my original post with what caddy output.

Thanks for the info – since you’re already pretty deep into figuring this out, would you be able to look at the source code and see why it is acting like this? That would be very helpful!

That error is coming from here, for reference:

The error is generated from the Go stdlib, i.e. net.DialContext