Caddy: Caddy fails to dial php-fpm occasionally
I'm trying to use php_fastcgi but I'm having this weird behavior where caddy sometimes stops processing the request with
"first_error":{"msg":"making dial info: upstream @api:: invalid dial address @api:: invalid start port: strconv.ParseUint: parsing \"\": invalid syntax"}}
> caddy run --config .\.caddyfile --adapter caddyfile --watch
2020/06/21 22:50:00.343 INFO using provided configuration {"config_file": ".\\.caddyfile", "config_adapter": "caddyfile"}
2020/06/21 22:50:00.351 INFO admin admin endpoint started {"address": "tcp/localhost:2019", "enforce_origin": false, "origins": ["127.0.0.1:2019", "localhost:2019", "[::1]:2019"]}
2020/06/22 01:50:00 [INFO][cache:0xc0000863c0] Started certificate maintenance routine
2020/06/21 22:50:00.354 INFO tls cleaned up storage units
2020/06/21 22:50:00.354 DEBUG http starting server loop {"address": "[::]:8081", "http3": false, "tls": false}
2020/06/21 22:50:00.355 INFO autosaved config {"file": "C:\\Users\\abdus\\AppData\\Roaming\\Caddy\\autosave.json"}
2020/06/21 22:50:00.355 INFO serving initial configuration
2020/06/21 22:50:00.355 INFO watcher watching config file for changes {"config_file": ".\\.caddyfile"}
2020/06/21 22:50:04.340 DEBUG http.handlers.rewrite rewrote request {"request": {"method": "GET", "uri": "/api", "proto": "HTTP/1.1", "remote_addr": "127.0.0.1:8288", "host": "localhost:8081", "headers": {"User-Agent": ["Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:78.0) Gecko/20100101 Firefox/78.0"], "Accept": ["text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"], "Accept-Language": ["de-DE,en-US;q=0.7,en;q=0.3"], "Accept-Encoding": ["gzip, deflate"], "Connection": ["keep-alive"], "Cookie": ["io=DGmJv34rjn1VFAsBAAAG"], "Upgrade-Insecure-Requests": ["1"]}}, "method": "GET", "uri": "index.php"}
2020/06/21 22:50:04.340 ERROR http.log.error making dial info: upstream @api:: invalid dial address @api:: invalid start port: strconv.ParseUint: parsing "": invalid syntax {"request": {"method": "GET", "uri": "/api", "proto": "HTTP/1.1", "remote_addr": "127.0.0.1:8288", "host": "localhost:8081", "headers": {"Upgrade-Insecure-Requests": ["1"], "User-Agent": ["Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:78.0) Gecko/20100101 Firefox/78.0"], "Accept": ["text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"], "Accept-Language": ["de-DE,en-US;q=0.7,en;q=0.3"], "Accept-Encoding": ["gzip, deflate"], "Connection": ["keep-alive"], "Cookie": ["io=DGmJv34rjn1VFAsBAAAG"]}}, "duration": 0.0009901}
2020/06/21 22:50:04.341 ERROR http.log.access handled request {"request": {"method": "GET", "uri": "/api", "proto": "HTTP/1.1", "remote_addr": "127.0.0.1:8288", "host": "localhost:8081", "headers": {"User-Agent": ["Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:78.0) Gecko/20100101 Firefox/78.0"], "Accept": ["text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8"], "Accept-Language": ["de-DE,en-US;q=0.7,en;q=0.3"], "Accept-Encoding": ["gzip, deflate"], "Connection": ["keep-alive"], "Cookie": ["io=DGmJv34rjn1VFAsBAAAG"], "Upgrade-Insecure-Requests": ["1"]}}, "common_log": "127.0.0.1 - - [22/Jun/2020:01:50:04 +0300] \"GET /api HTTP/1.1\" 500 0", "duration": 0.0009901, "size": 0, "status": 500, "resp_headers": {"Server": ["Caddy"]}}
This is my caddyfile
{
debug
}
http://localhost:8081
@api path /api*
php_fastcgi @api 127.0.0.1:9090
root @api api/public
file_server
@static not path /api*
handle @static {
root dist
file_server
}
log
The error led me to believe there was something wrong with my php_fastcgi directive, I tried using a unix socket, this time I get invalid start port: error
https://github.com/caddyserver/caddy/blob/f5ccb904a3db2bffd980feee685afaa762224cb2/listeners.go#L363
I've tried removing matchers and using raw path globs, but no avail. Here's a demo where I keep refreshing the page:
> caddy version
v2.1.0-beta.1 h1:nG+Y2NuoqGvJEnHlVO5PXtTxuc2yHsjr2nU+dJ5yETk=
> systeminfo
OS Name: Microsoft Windows 10 Enterprise Insider Preview
OS Version: 10.0.19582 N/A Build 19582
> php-cgi --version
PHP 7.4.2 (cgi-fcgi) (built: Jan 21 2020 17:52:21)
Copyright (c) The PHP Group
Zend Engine v3.4.0, Copyright (c) Zend Technologies
abdusco
All 6 comments
Downgraded to v2.0, it's working as expected. I get a response every time. I guess there's been a regression.
```
prime@klein /a/w/abdus.dev> caddy version
v2.0.0 h1:pQSaIJGFluFvu8KDGDODV8u4/QRED/OPyIR+MWYYse8=
````
abdusco
on 22 Jun 2020
Very interesting. Your Caddyfile adapts to this:
{
"logging": {
"logs": {
"default": {
"level": "DEBUG"
}
}
},
"apps": {
"http": {
"servers": {
"srv0": {
"listen": [
":8081"
],
"routes": [
{
"match": [
{
"host": [
"localhost"
]
}
],
"handle": [
{
"handler": "subroute",
"routes": [
{
"handle": [
{
"handler": "vars",
"root": "api/public"
}
],
"match": [
{
"path": [
"/api*"
]
}
]
},
{
"handle": [
{
"handler": "subroute",
"routes": [
{
"handle": [
{
"handler": "vars",
"root": "dist"
},
{
"handler": "file_server",
"hide": [
"Caddyfile"
]
}
]
}
]
}
],
"match": [
{
"not": [
{
"path": [
"/api*"
]
}
]
}
]
},
{
"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": [
"*/"
]
}
]
}
]
},
{
"handle": [
{
"handler": "rewrite",
"uri": "{http.matchers.file.relative}"
}
],
"match": [
{
"file": {
"split_path": [
".php"
],
"try_files": [
"{http.request.uri.path}",
"{http.request.uri.path}/index.php",
"index.php"
]
}
}
]
},
{
"handle": [
{
"handler": "reverse_proxy",
"transport": {
"protocol": "fastcgi",
"split_path": [
".php"
]
},
"upstreams": [
{
"dial": "@api:"
},
{
"dial": "127.0.0.1:9090"
}
]
}
],
"match": [
{
"path": [
"*.php"
]
}
]
},
{
"handle": [
{
"handler": "file_server",
"hide": [
"Caddyfile"
]
}
]
}
]
}
],
"terminal": true
}
],
"automatic_https": {
"skip": [
"localhost"
]
},
"logs": {}
}
}
}
}
}
You'll notice that the proxy has two upstreams, one being @api:. I'll look into it. Thanks for pointing it out!
francislavoie
on 22 Jun 2020
Thanks, that was an easy fix. The regression happened in #3255, where I refactored the Caddyfile parsing of php_fastcgi to add some new features. It inadvertently broke matcher tokens, and instead caused them to be read in as proxy upstreams. Whoops!
I opened PR #3512 with a fix.
Thanks so much for trying the beta, we should be able to get this fix in for the next v2.1 beta, or at least before the v2.1 stable release.
francislavoie
on 22 Jun 2020
Thank you! What would we do without you, @francislavoie .
mholt
on 22 Jun 2020
I still see similar behaviour on v2.1.1.
This is my caddyfile:
example.com {
root * /var/www/html
@indexFiles {
file {
try_files {path} /index.php?it={path}&{query}
split_path .php
}
}
rewrite @indexFiles {http.matchers.file.relative}
php_fastcgi unix//run/php/custom.php-fpm.sock php {
env HTTP_HOST "example.com"
env HTTP_MOD_REWRITE "On"
}
file_server
}
LostKobrakai
on 15 Sep 2020
Ah, spotted the issue: php_fastcgi unix//run/php/custom.php-fpm.sock php {, the php was left from converting from an v1 caddyfile.
LostKobrakai
on 15 Sep 2020
Related issues
whs
路
3Comments
dafanasiev
路
3Comments
ericmdantas
路
3Comments
SteffenDE
路
3Comments
xfzka
路
3Comments
Most helpful comment
Ah, spotted the issue:
php_fastcgi unix//run/php/custom.php-fpm.sock php {, thephpwas left from converting from an v1 caddyfile.