caddy icon indicating copy to clipboard operation
caddy copied to clipboard
verified publisher icon caddyserver

After reboot long time to start

Open millosz222 opened this issue 8 months ago • 5 comments

Hello,

We are experiencing a problem with our Caddy instance after a reboot—it fails to start due to a timeout.

What I’ve noticed is that it takes a long time to process the warnings below. However, if I try to start it again, it’s a bit faster and eventually does start.

I have already set the service timeout to 180 seconds, but I’m not sure if increasing the timeout to 5 minutes would solve the issue, or if there is a different underlying problem. Currently, our service configuration is:

[Service]
TimeoutStartSec=180s

Caddy version:

v2.8.4 h1:q3pe0wpBj1OcHFZ3n/1nl4V4bxBrYoSoab7rL9BMYNk=

We built our own version due to issues after reboot, as described here:
https://github.com/caddyserver/certmagic/issues/303

Build command used:

xcaddy build --with github.com/caddyserver/certmagic@16e2e0b

Do you have any suggestions on how to resolve this, or should we just increase the timeout further?

May 12 23:19:12 az01sx0113 caddy[524]: {"level":"info","ts":1747091952.9932868,"logger":"tls","msg":"storage cleaning happened too recently; skipping for now","storage":"FileStorage:/mnt/xxxxxxxx","instance":"eb4e1241-935f-46e0-a437-5f34d6302485","try_again":1749683952.9932845,"try_again_in":2591999.999999359}
May 12 23:19:13 az01sx0113 caddy[524]: {"level":"info","ts":1747091953.0188017,"logger":"tls","msg":"finished cleaning storage units"}
May 12 23:19:27 az01sx0113 caddy[524]: {"level":"warn","ts":1747091967.227589,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxx"]}
May 12 23:19:36 az01sx0113 caddy[524]: {"level":"warn","ts":1747091976.1332324,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxxxxxxxxx"]}
May 12 23:19:54 az01sx0113 caddy[524]: {"level":"warn","ts":1747091994.714365,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxxxxxx"]}
May 12 23:20:11 az01sx0113 caddy[524]: {"level":"warn","ts":1747092011.904902,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxx"]}
May 12 23:20:16 az01sx0113 caddy[524]: {"level":"warn","ts":1747092016.3602548,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxxx"]}
May 12 23:20:17 az01sx0113 caddy[524]: {"level":"warn","ts":1747092017.4758875,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxxx"]}
May 12 23:20:17 az01sx0113 caddy[524]: {"level":"warn","ts":1747092017.646079,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxxx]: parsing OCSP response: asn1: structure error: tags don't match (16 vs {class:0 tag:28 length:72 isCompound:true}) {optional:false explicit:false application:false private:false defaultValue:<nil> tag:<nil> stringType:0 timeType:0 set:false omitEmpty:false} responseASN1 @2","identifiers":["xxxxxxx"]}
May 12 23:20:17 az01sx0113 caddy[524]: {"level":"warn","ts":1747092017.829414,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxx]: parsing OCSP response: asn1: structure error: tags don't match (16 vs {class:0 tag:28 length:72 isCompound:true}) {optional:false explicit:false application:false private:false defaultValue:<nil> tag:<nil> stringType:0 timeType:0 set:false omitEmpty:false} responseASN1 @2","identifiers":["xxxxxx"]}
May 12 23:20:18 az01sx0113 caddy[524]: {"level":"warn","ts":1747092018.062228,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxx]: parsing OCSP response: asn1: structure error: tags don't match (16 vs {class:0 tag:28 length:72 isCompound:true}) {optional:false explicit:false application:false private:false defaultValue:<nil> tag:<nil> stringType:0 timeType:0 set:false omitEmpty:false} responseASN1 @2","identifiers":["xxxxxxxx"]}
May 12 23:20:18 az01sx0113 caddy[524]: {"level":"warn","ts":1747092018.2552805,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxx]: parsing OCSP response: asn1: structure error: tags don't match (16 vs {class:0 tag:28 length:72 isCompound:true}) {optional:false explicit:false application:false private:false defaultValue:<nil> tag:<nil> stringType:0 timeType:0 set:false omitEmpty:false} responseASN1 @2","identifiers":["xxxxxxxx"]}
May 12 23:20:22 az01sx0113 caddy[524]: {"level":"warn","ts":1747092022.9520185,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxxxx"]}
May 12 23:20:23 az01sx0113 caddy[524]: {"level":"warn","ts":1747092023.3026285,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxxxxx"]}
May 12 23:20:24 az01sx0113 caddy[524]: {"level":"warn","ts":1747092024.777097,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxxx"]}
May 12 23:20:59 az01sx0113 caddy[524]: {"level":"warn","ts":1747092059.2971482,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxxxx"]}
May 12 23:21:21 az01sx0113 caddy[524]: {"level":"warn","ts":1747092081.1364572,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxxxxx"]}
May 12 23:21:43 az01sx0113 caddy[524]: {"level":"warn","ts":1747092103.3426826,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxxxxxxxx"]}
May 12 23:22:04 az01sx0113 caddy[524]: {"level":"warn","ts":1747092124.7263947,"logger":"tls","msg":"stapling OCSP","error":"no OCSP stapling for [xxxxxxxxxx]: no OCSP server specified in certificate","identifiers":["xxxxxxxxxxxx"]}
May 12 23:22:10 az01sx0113 systemd[1]: caddy.service: start operation timed out. Terminating.
May 12 23:22:10 az01sx0113 caddy[524]: {"level":"info","ts":1747092130.224219,"msg":"shutting down apps, then terminating","signal":"SIGTERM"}
May 12 23:22:10 az01sx0113 caddy[524]: {"level":"warn","ts":1747092130.224349,"msg":"exiting; byeee!! 👋","signal":"SIGTERM"}
May 12 23:22:15 az01sx0113 systemd[1]: caddy.service: State 'stop-sigterm' timed out. Killing.



May 12 23:22:10 az01sx0113 systemd[1]: caddy.service: start operation timed out. Terminating.
May 12 23:22:10 az01sx0113 caddy[524]: {"level":"info","ts":1747092130.224219,"msg":"shutting down apps, then terminating","signal":"SIGTERM"}
May 12 23:22:10 az01sx0113 caddy[524]: {"level":"warn","ts":1747092130.224349,"msg":"exiting; byeee!! 👋","signal":"SIGTERM"}
May 12 23:22:15 az01sx0113 systemd[1]: caddy.service: State 'stop-sigterm' timed out. Killing.
May 12 23:22:15 az01sx0113 systemd[1]: caddy.service: Killing process 524 (caddy) with signal SIGKILL.
May 12 23:22:15 az01sx0113 systemd[1]: caddy.service: Killing process 612 (caddy) with signal SIGKILL.
May 12 23:22:15 az01sx0113 systemd[1]: caddy.service: Killing process 613 (caddy) with signal SIGKILL.
May 12 23:22:15 az01sx0113 systemd[1]: caddy.service: Killing process 650 (caddy) with signal SIGKILL.
May 12 23:22:15 az01sx0113 systemd[1]: caddy.service: Killing process 760 (caddy) with signal SIGKILL.
May 12 23:22:15 az01sx0113 systemd[1]: caddy.service: Killing process 762 (caddy) with signal SIGKILL.
May 12 23:22:15 az01sx0113 systemd[1]: caddy.service: Killing process 1012 (caddy) with signal SIGKILL.
May 12 23:22:15 az01sx0113 systemd[1]: caddy.service: Main process exited, code=killed, status=9/KILL
May 12 23:22:15 az01sx0113 systemd[1]: caddy.service: Failed with result 'timeout'.
May 12 23:22:15 az01sx0113 systemd[1]: Failed to start Caddy.
May 12 23:22:15 az01sx0113 systemd[1]: caddy.service: Consumed 3.990s CPU time.

millosz222 avatar May 13 '25 09:05 millosz222

See https://letsencrypt.org/2024/12/05/ending-ocsp/

Please upgrade to the latest version of Caddy. You're on a old version from a year ago.

francislavoie avatar May 13 '25 09:05 francislavoie

I suppose it would be advisable for anyone using only Let's Encrypt certificates issued after May 7th to add ocsp_stapling off to the global options in order to avoid WARN log entries containing the "error" message.

2025-05-13T14:01:45.066+0200   WARN    tls     stapling OCSP   {"error": "no OCSP stapling for [ocsp-test.stbu.net]: no OCSP server specified in certificate", "identifiers": ["ocsp-test.stbu.net"]}

steffenbusch avatar May 13 '25 12:05 steffenbusch

I suppose it would be advisable for anyone using only Let's Encrypt certificates issued after May 7th to add ocsp_stapling off to the global options in order to avoid WARN log entries containing the "error" message.

2025-05-13T14:01:45.066+0200   WARN    tls     stapling OCSP   {"error": "no OCSP stapling for [ocsp-test.stbu.net]: no OCSP server specified in certificate", "identifiers": ["ocsp-test.stbu.net"]}

does it apply to zerossl as well? we use a default scenario where caddy is failover to zerossl

millosz222 avatar May 13 '25 12:05 millosz222

The OCSP warnings are red herrings. We'll need more information:

  • What are the full, unredacted logs?
  • What is your full, unredacted (other than credentials) config?

Actually, here is a bug report template to make this easier:

Ideally, we need to be able to reproduce the bug in the most minimal way possible using the latest version of Caddy. 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)

This should be the latest version of Caddy:

```
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)

Instructions -- please heed otherwise we cannot help you (help us help you!)

  1. 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.

  2. 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. Please enable debug and access logs.
    • 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.

  3. 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 ___.

mholt avatar May 13 '25 18:05 mholt

hey @mholt before I proceed with bug report. I will just give a try with update to latest version, and then I will what next. but thanks for info

millosz222 avatar May 13 '25 18:05 millosz222