caddyfile config mistake causes panic

Created on 18 Sep 2020 · 12Comments · Source: caddyserver/caddy

curl: (92) HTTP/2 stream 0 was not closed cleanly: INTERNAL_ERROR (err 2)

and

2020/09/18 05:06:04.004 DEBUG   http.stdlib     http2: panic serving 100.90.14.63:53490: inconsistent label cardinality: expected 4 label values but got 3 in prometheus.Labels{"handler":"headers", "method":"GET", "server":"srv0"}
goroutine 192 [running]:
net/http.(*http2serverConn).runHandler.func1(0xc000b6c1d0, 0xc000c07f8e, 0xc000103200)
        net/http/h2_bundle.go:5713 +0x16b
panic(0x1667f20, 0xc0005d07a0)
        runtime/panic.go:969 +0x166
github.com/prometheus/client_golang/prometheus.(*HistogramVec).With(0xc000206ea0, 0xc00070b350, 0x7fd93854a298, 0xc00056a3c0)
        github.com/prometheus/[email protected]/prometheus/histogram.go:501 +0xc2
github.com/caddyserver/caddy/v2/modules/caddyhttp.(*metricsInstrumentedHandler).ServeHTTP(0xc000b925c0, 0x7fd93823a6a0, 0xc00070b2f0, 0xc000533300, 0x1c03c20, 0xc000dcc240, 0x0, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/metrics.go:137 +0x630
github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1(0x7fd93823a6a0, 0xc00070b2f0, 0xc000533300, 0xc0009bcfc0, 0xc000dcc0c0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/routes.go:259 +0x5a
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000dcc280, 0x7fd93823a6a0, 0xc00070b2f0, 0xc000533300, 0x0, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/caddyhttp.go:58 +0x44
github.com/caddyserver/caddy/v2/modules/caddyhttp/headers.Handler.ServeHTTP(0xc000b905a0, 0x0, 0x7fd93823a6a0, 0xc00070b2f0, 0xc000533300, 0x1c03c20, 0xc000dcc280, 0xc000414e00, 0x7fd93823a6a0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/headers/headers.go:110 +0x184
github.com/caddyserver/caddy/v2/modules/caddyhttp.(*metricsInstrumentedHandler).ServeHTTP(0xc000b925a0, 0x7fd93823a6a0, 0xc00070b230, 0xc000533300, 0x1c03c20, 0xc000dcc280, 0x0, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/metrics.go:129 +0x4c3
github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1(0x7fd93823a6a0, 0xc00070b230, 0xc000533300, 0x0, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/routes.go:259 +0x5a
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000dcc2a0, 0x7fd93823a6a0, 0xc00070b230, 0xc000533300, 0x0, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/caddyhttp.go:58 +0x44
github.com/caddyserver/caddy/v2/modules/caddyhttp/headers.Handler.ServeHTTP(0x0, 0xc000b920a0, 0x7fd93823a6a0, 0xc00070b230, 0xc000533300, 0x1c03c20, 0xc000dcc2a0, 0xc000412400, 0x7fd93823a6a0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/headers/headers.go:110 +0x184
github.com/caddyserver/caddy/v2/modules/caddyhttp.(*metricsInstrumentedHandler).ServeHTTP(0xc000b92560, 0x7fd93823a6a0, 0xc00070b170, 0xc000533300, 0x1c03c20, 0xc000dcc2a0, 0x0, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/metrics.go:129 +0x4c3
github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1(0x7fd93823a6a0, 0xc00070b170, 0xc000533300, 0x0, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/routes.go:259 +0x5a
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000dcc2c0, 0x7fd93823a6a0, 0xc00070b170, 0xc000533300, 0x0, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/caddyhttp.go:58 +0x44
github.com/caddyserver/caddy/v2/modules/caddyhttp/headers.Handler.ServeHTTP(0x0, 0xc000a6dea0, 0x7fd93823a6a0, 0xc00070b170, 0xc000533300, 0x1c03c20, 0xc000dcc2c0, 0xc00040fa00, 0x7fd93823a6a0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/headers/headers.go:110 +0x184
github.com/caddyserver/caddy/v2/modules/caddyhttp.(*metricsInstrumentedHandler).ServeHTTP(0xc000b92540, 0x7fd93823a6a0, 0xc00070b080, 0xc000533300, 0x1c03c20, 0xc000dcc2c0, 0x0, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/metrics.go:129 +0x4c3
github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1(0x7fd93823a6a0, 0xc00070b080, 0xc000533300, 0xc00070b001, 0xc000cff8c0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/routes.go:259 +0x5a
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000dcc2e0, 0x7fd93823a6a0, 0xc00070b080, 0xc000533300, 0xc000cff958, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/caddyhttp.go:58 +0x44
github.com/SvenDowideit/caddy-sessionid.SessionID.ServeHTTP(0xc000b7fd00, 0xf, 0x7fd93823a6a0, 0xc00070b080, 0xc000533300, 0x1c03c20, 0xc000dcc2e0, 0xc000409000, 0x7fd93823a6a0)
        github.com/SvenDowideit/[email protected]/sessionid.go:75 +0x2e7
github.com/caddyserver/caddy/v2/modules/caddyhttp.(*metricsInstrumentedHandler).ServeHTTP(0xc000b92520, 0x7fd93823a6a0, 0xc00070afc0, 0xc000533300, 0x1c03c20, 0xc000dcc2e0, 0x0, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/metrics.go:129 +0x4c3
github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1(0x7fd93823a6a0, 0xc00070afc0, 0xc000533300, 0xc000dcc300, 0xc000b92520)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/routes.go:259 +0x5a
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000dcc300, 0x7fd93823a6a0, 0xc00070afc0, 0xc000533300, 0x1, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/caddyhttp.go:58 +0x44
github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapRoute.func1.1(0x7fd93823a6a0, 0xc00070afc0, 0xc000533300, 0x1, 0x1)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/routes.go:231 +0x121
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000dcc260, 0x7fd93823a6a0, 0xc00070afc0, 0xc000533300, 0x1993928, 0x1c03c20)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/caddyhttp.go:58 +0x44
github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Subroute).ServeHTTP(0xc000a6d840, 0x7fd93823a6a0, 0xc00070afc0, 0xc000533300, 0x1c03c20, 0x1993928, 0xf, 0x203000)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/subroute.go:74 +0x8a
github.com/caddyserver/caddy/v2/modules/caddyhttp.(*metricsInstrumentedHandler).ServeHTTP(0xc000ba3460, 0x1c20940, 0xc000b6c1d0, 0xc000533300, 0x1c03c20, 0x1993928, 0x0, 0x0)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/metrics.go:129 +0x4c3
github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1(0x1c20940, 0xc000b6c1d0, 0xc000533300, 0xc000dcc1c0, 0xc000ba3460)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/routes.go:259 +0x5a
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000dcc1c0, 0x1c20940, 0xc000b6c1d0, 0xc000533300, 0xc0007b9501, 0xfa04b8)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/caddyhttp.go:58 +0x44
github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapRoute.func1.1(0x1c20940, 0xc000b6c1d0, 0xc000533300, 0x0, 0xc000a49a40)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/routes.go:231 +0x121
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000bb6060, 0x1c20940, 0xc000b6c1d0, 0xc000533300, 0xc0007b9600, 0xfa04b8)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/caddyhttp.go:58 +0x44
github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapRoute.func1.1(0x1c20940, 0xc000b6c1d0, 0xc000533300, 0x0, 0xc000a49920)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/routes.go:203 +0x2ec
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000bb6080, 0x1c20940, 0xc000b6c1d0, 0xc000533300, 0x0, 0x17d3380)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/caddyhttp.go:58 +0x44
github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapRoute.func1.1(0x1c20940, 0xc000b6c1d0, 0xc000533300, 0xc000a95808, 0x40c976)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/routes.go:203 +0x2ec
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000bb60a0, 0x1c20940, 0xc000b6c1d0, 0xc000533300, 0x7, 0x2)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/caddyhttp.go:58 +0x44
github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).enforcementHandler(0xc000a2eea0, 0x1c20940, 0xc000b6c1d0, 0xc000533300, 0x1c03c20, 0xc000bb60a0, 0x2a44a7d88d91, 0x4013f3)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/server.go:279 +0x9b
github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).wrapPrimaryRoute.func1(0x1c20940, 0xc000b6c1d0, 0xc000533300, 0xc0004013f3, 0x2a44a7d88d91)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/server.go:255 +0x5a
github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP(0xc000bb60c0, 0x1c20940, 0xc000b6c1d0, 0xc000533300, 0xc000cf9d00, 0xc000533300)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/caddyhttp.go:58 +0x44
github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).ServeHTTP(0xc000a2eea0, 0x1c20940, 0xc000b6c1d0, 0xc000533300)
        github.com/caddyserver/caddy/[email protected]/modules/caddyhttp/server.go:204 +0x4b3
net/http.serverHandler.ServeHTTP(0xc000a062a0, 0x1c20940, 0xc000b6c1d0, 0xc000912c00)
        net/http/server.go:2836 +0xa3
net/http.initALPNRequest.ServeHTTP(0x1c282c0, 0xc00089f110, 0xc0008aa000, 0xc000a062a0, 0x1c20940, 0xc000b6c1d0, 0xc000912c00)
        net/http/server.go:3410 +0x8d
net/http.(*http2serverConn).runHandler(0xc000103200, 0xc000b6c1d0, 0xc000912c00, 0xc0008d9460)
        net/http/h2_bundle.go:5720 +0x8b
created by net/http.(*http2serverConn).processHeaders
        net/http/h2_bundle.go:5454 +0x4e1

bug

Source

SvenDowideit

Most helpful comment

ok, I can confirm that the panic is gone - @hairyhenderson

SvenDowideit on 23 Sep 2020

👍2

All 12 comments

Thanks for the report! There's reference to Prometheus and mention of Caddyfile config mistake. Can you share more details please?

Ideally, we need to be able to reproduce the bug _in the most minimal way possible_. This allows us to write regression tests to verify the fix is working. If we can't reproduce it, then you'll have to test our changes for us until it's fixed -- and then we can't add test cases, either.

I've attached a template below that will help make this easier and faster! This will require some effort on your part -- please understand that we will be dedicating time to fix the bug you are reporting if you can just help us understand it and reproduce it easily.

This template will ask for some information you've already provided; that's OK, just fill it out the best you can. :+1: I've also included some helpful tips below the template. Feel free to let me know if you have any questions!

Thank you again for your report, we look forward to resolving it!

Template

## 1. Environment

### 1a. Operating system and version

paste here


1b. Caddy version (run caddy version or paste commit SHA)

paste here


1c. Go version (if building Caddy from source; run go version)

paste here


2. Description

2a. What happens (briefly explain what is wrong)

2b. Why it's a bug (if it's not obvious)

2c. Log output

paste terminal output or logs here


2d. Workaround(s)

2e. Relevant links

3. Tutorial (minimal steps to reproduce the bug)

Helpful tips

Environment: Please fill out your OS and Caddy versions, even if you don't think they are relevant. (They are _always_ relevant.) If you built Caddy from source, provide the commit SHA and specify your exact Go version.
Description: Describe at a high level what the bug is. What happens? Why is it a bug? Not all bugs are obvious, so convince readers that it's actually a bug.
- 2c) Log output: Paste terminal output and/or complete logs in a code block. DO NOT REDACT INFORMATION except for credentials.
- 2d) Workaround: What are you doing to work around the problem in the meantime? This can help others who encounter the same problem, until we implement a fix.
- 2e) Relevant links: Please link to any related issues, pull requests, docs, and/or discussion. This can add crucial context to your report.
Tutorial: What are the _minimum required specific steps_ someone needs to take in order to experience the same bug? Your goal here is to make sure that anyone else can have the same experience with the bug as you do. You are writing a tutorial, so make sure to carry it out yourself before posting it. Please:
- Start with an empty config. Add _only_ the lines/parameters that are _absolutely required_ to reproduce the bug.
- Do not run Caddy inside containers.
- Run Caddy manually in your terminal; do not use systemd or other init systems.
- If making HTTP requests, avoid web browsers. Use a simpler HTTP client instead, like curl.
- Do not redact any information from your config (except credentials). Domain names are public knowledge and often necessary for quick resolution of an issue!
- Note that ignoring this advice may result in delays, or even in your issue being closed. 😞 Only actionable issues are kept open, and if there is not enough information or clarity to reproduce the bug, then the report is not actionable.

Example of a tutorial:

Create a config file:
{ ... }
Open terminal and run Caddy:
$ caddy ...
Make an HTTP request:
$ curl ...
Notice that the result is ___ but it should be ___.

Mohammed90 on 18 Sep 2020

seems to happen when I put templates inside the route @auth section (commented out)

*.x1carbon.ona.im x1carbon.ona.im {
    session_id x1carbon.ona.im
    header * x-session-id "{http.session_id}"
    header * x-session-role "{http.session_role}"

    @auth {
            host auth.x1carbon.ona.im
    }
    route @auth {
        # doesn't seem to process templates from here
        root * /auth_html/
        file_server browse
        #templates     # <--- causes panic?
    }
    templates
}

SvenDowideit on 18 Sep 2020

Oo thanks; with the full stack trace and that extra tid bit of config info, that might be enough to be able to reproduce it. I've tagged Dave since he knows this part of the code best, but I'll also help take a look at it tomorrow.

mholt on 18 Sep 2020

👍1

I'm not using the prometheus plugin - the xcaddy line i'm using to build this is

RUN xcaddy build master \
    --with github.com/SvenDowideit/caddy-sessionid@b9f3455d4a99c3de086075c192546882a8f83fc6 \
    --with github.com/caddy-dns/gandi \
    --with github.com/caddy-dns/digitalocean \
    --with github.com/lucaslorentz/caddy-docker-proxy/plugin/v2=/src/plugin/

SvenDowideit on 18 Sep 2020

👍2

yeah, I'm still exploring the problem, as its very much part of the overly complicated things i'm throwing together for a demo

SvenDowideit on 18 Sep 2020

This release candidate adds integrated metrics so you won't need a separate prometheus plugin in the future.

Sorry about this, hopefully we can get this patched before your demo!

mholt on 18 Sep 2020

the crash looks to be easy enough to workaround - the main pest was that it was the first time i'd used templates, file_browse, etc, cos I thought i'd mock up the auth page - I have a workaround (putting the templates in the other location), but i'm pretty curious what the side effects of that are

SvenDowideit on 18 Sep 2020

oh - and don't rush, it looks like the demo won't be for a week or so :) there's just a bunch more stuff for me to mock up, and then i need to move off to deal with HPC workflow stuff

SvenDowideit on 18 Sep 2020

Agh. Sorry about this @SvenDowideit, I wonder if it's related to the bug I fixed in #3733 - though this is a different error (albeit around the same code).

The important message is inconsistent label cardinality: expected 4 label values but got 3 in prometheus.Labels{"handler":"headers", "method":"GET", "server":"srv0"}.

And indeed, that label set needs a "code" label. It's _supposed_ to be added after the header's written, but there seems to have been a case where it wasn't, and when the metric was observed here, it panicked.

@SvenDowideit If possible, could you paste the output from curl http://localhost:2019/metrics right after you get that panic?

I don't need that output to fix the bug (it's a simple case of checking), but I'm curious to see specifically if caddy_http_ response_duration_seconds exists, and if it has a "code" label, and what the value is!

hairyhenderson on 19 Sep 2020

👍1

This is actually pretty easy to reproduce - it has nothing to do with the templates directive. This Caddyfile will trigger it:

localhost

respond /foo "yo"

When hitting /foo, everything's fine. When there's a request that's otherwise unhandled, we get the panic.

So in your case, @SvenDowideit, I think your panicking request isn't matching @auth.

The reasoning is that my code assumes that the header's _always_ going to be written, but in this case the emptyHandler is hit (as a fallthrough), which neither returns an error nor writes the header. I'll have a PR to fix this in a few minutes.

hairyhenderson on 19 Sep 2020

❤2

awesome! thanks - I'll build and test later in the week, its "meeting day" here :)

SvenDowideit on 22 Sep 2020

👍1

ok, I can confirm that the panic is gone - @hairyhenderson

SvenDowideit on 23 Sep 2020

👍2

Was this page helpful?

0 / 5 - 0 ratings

Related issues

Proxy preset `transparent` should use X-Forwarded-Host {host}

treviser · 3Comments

Rename Let's Encrypt to Certbot?

ericmdantas · 3Comments

Caddyfile lexer bug

dafanasiev · 3Comments

Hosting Shopware

PhilmacFLy · 3Comments

webdav plugin seems no longer to be maintained.

mikolysz · 3Comments

caddyfile config mistake causes panic

Most helpful comment

All 12 comments

Template

1b. Caddy version (run `caddy version` or paste commit SHA)

1c. Go version (if building Caddy from source; run `go version`)

2. Description

2a. What happens (briefly explain what is wrong)

2b. Why it's a bug (if it's not obvious)

2c. Log output

2d. Workaround(s)

2e. Relevant links

3. Tutorial (minimal steps to reproduce the bug)

Helpful tips

Related issues