Repository: caddyserver/caddy (language: go)

Issue:
Caddy 2.6.3 high memory usage
We are using Caddy on Ubuntu 20.04 on of our servers as a reverse-proxy for our Docker registry and are regularly pulling and pushing Docker images to and from this registry. The server had initially 8GB of memory and everything worked fine with Caddy 2.6.2.

After updating to Caddy 2.6.3 the server regularly runs out of memory when building and publishing new Docker images via our CI system and Caddy gets killed because of that (see below). This still happens even after we increased the server memory to 16GB + 32GB swap.

A downgrade to 2.6.2 fixes the issue.

Did some configuration defaults change in the new version? Is there a way to limit the memory usage? Is there maybe a memory leak in 2.6.3?

```
~$ dmesg -T | egrep -i 'killed process'
[Fri Feb 10 13:45:11 2023] Out of memory: Killed process 792 (caddy) total-vm:45205552kB, anon-rss:14974688kB, file-rss:0kB, shmem-rss:0kB, UID:997 pgtables:86664kB oom_score_adj:0
[Fri Feb 10 13:50:59 2023] Out of memory: Killed process 2876 (caddy) total-vm:45738576kB, anon-rss:14941248kB, file-rss:0kB, shmem-rss:0kB, UID:997 pgtables:86736kB oom_score_adj:0
```


Discussion / hints:
Is the build step that's running out of memory, or the Caddy server itself?

Please share the steps to reproduce. If it's the build, share your build process. If it's Caddy itself, fill out the form below. Also, please share the output of `http://localhost:2019/debug/pprof`.


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

<pre><code>## 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)




</code></pre>

## Helpful tips

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.](https://caddy.community/t/how-to-get-help-with-caddy-more-effectively/5222)
	- **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](https://caddy.community/t/how-to-get-help-with-caddy-more-effectively/5222)!
	- 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:

<blockquote>Create a config file:

```
{ ... }
```

Open terminal and run Caddy:

```
$ caddy ...
```

Make an HTTP request:

```
$ curl ...
```

Notice that the result is ___ but it should be ___.</blockquote>
## 1. Environment

### 1a. Operating system and version

```
NAME="Ubuntu"
VERSION="20.04.5 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.5 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal
```


### 1b. Caddy version (run `caddy version` or paste commit SHA)

```
v2.6.3 h1:QRVBNIqfpqZ1eJacY44I6eUC1OcxQ8D04EKImzpj7S8=
```


### 1c. Go version (if building Caddy from source; run `go version`)
n/a

Caddy is installed from the [APT repository](https://caddyserver.com/docs/install#debian-ubuntu-raspbian).

## 2. Description

### 2a. What happens (briefly explain what is wrong)
**Server 1**: Caddy runs as a reverse-proxy for a Docker registry / Sonatype Nexus Repository (both on the same server), configured via e.g. `reverse_proxy localhost:8004`.
**Server 2**: Builds and publishes Docker images to the registry on **Server 1**. While building new images, layers might also be pulled from **Server 1**. 

**Server 1** runs out of memory because Caddy 2.6.3 uses huge amounts of memory. Caddy then gets killed by the system.
```
~$ dmesg -T | egrep -i 'killed process'
[Fri Feb 10 13:45:11 2023] Out of memory: Killed process 792 (caddy) total-vm:45205552kB, anon-rss:14974688kB, file-rss:0kB, shmem-rss:0kB, UID:997 pgtables:86664kB oom_score_adj:0
[Fri Feb 10 13:50:59 2023] Out of memory: Killed process 2876 (caddy) total-vm:45738576kB, anon-rss:14941248kB, file-rss:0kB, shmem-rss:0kB, UID:997 pgtables:86736kB oom_score_adj:0
```

### 2b. Why it's a bug (if it's not obvious)
The same process from **2a** worked fine with Caddy 2.6.2, when **Server 1** had only 8 GB of RAM.
The process from **2a** fails with Caddy 2.6.3 with 8 GB of RAM and even with 48 GB (16 GB + 32 GB swapfile).



### 2c. Log output
There is no log output after Caddy is started until it gets killed by the system. These are the lines from `journalctl`:

```
Feb 10 13:41:08 dev-3.redacted.domain systemd[1]: Started Caddy.
Feb 10 13:45:13 dev-3.redacted.domain systemd[1]: caddy.service: Main process exited, code=killed, status=9/KILL
Feb 10 13:45:13 dev-3.redacted.domain systemd[1]: caddy.service: Failed with result 'signal'.
```



### 2d. Workaround(s)
A downgrade to Caddy 2.6.2 fixes the issue.



### 2e. Relevant links
n/a



## 3. Tutorial (minimal steps to reproduce the bug)
Unfortunately, I currently have no simple steps to reproduce the issue outside of our environment.

Output of `http://localhost:2019/debug/pprof`:

Count | Profile
-- | --
268 | allocs
0 | block
0 | cmdline
27 | goroutine
268 | heap
0 | mutex
0 | profile
13 | threadcreate
0 | trace
My hunch is Caddy is probably buffering the request and/or response in the reverse-proxy handler due to the changes of #5289. Try [disabling buffering](https://caddyserver.com/docs/caddyfile/directives/reverse_proxy#streaming) by setting `flush_interval` to `-1`. Is it possible to try and report back?


I have changed the config from
```
  reverse_proxy localhost:8004
```
to
``` 
reverse_proxy localhost:8004 {
    flush_interval -1
}
```
and restarted Caddy. It doesn't seem to have an effect. The memory still gets filled up pretty quickly when starting the process again.
@GerritKopp What is your full, unredacted config? What is the output of `top` (or `htop`) just before a crash?

Can you please collect a heap profile? That is what we mean when we talk about that debug/pprof endpoint -- not just the counts next to the links :) For example, for a 30 second heap profile, add `?seconds=30` to that link. If you could also provide the dump of goroutines that's often very helpful.
To reproduce the results faster, the server was configured with 16 GB RAM and no swap file. Caddy 2.6.2 had no issues with the same setup with only 8 GB.

I tried to collect all the requested metrics. Since Caddy gets killed the heap-delta had to stop earlier. I ran `top` in batch mode, starting when Caddy was idle until after Caddy was killed.

The goroutines dump is from another run performing the same tasks, when the server was nearly maxed out on memory again.

All files in an archive: [top-output-and-heap-profile.zip](https://github.com/caddyserver/caddy/files/10709394/top-output-and-heap-profile.zip)

Caddyfile (with redacted credentials):
```
(error_pages) {
  handle_errors {
    header content-type "text/html"
    respond * "" {http.error.status_code} {
      import error_snippet
      close
    }
  }
}

(error_snippet) {
body "<!DOCTYPE html>
<html>
  <title>Error {http.error.status_code}</title>
  <p>Error {http.error.status_code}</p>
</html>
"
}

entwicklung-3.t2med.eu {
  root * /usr/share/caddy
  file_server

  import error_pages

  handle_path /monitoring/prometheus* {
    rewrite * /metrics{path}
    reverse_proxy localhost:9100
    basicauth * {
      hidden-user hidden-password
    }
  }
}

nexus.t2med.eu {
  reverse_proxy localhost:8002
  import error_pages
}

docker.t2med.eu {
  reverse_proxy localhost:8003
  import error_pages
}

upload.docker.t2med.eu {
  reverse_proxy localhost:8004
  import error_pages
}
```

I hope this information is useful.

Thanks! Yeah that is way more insight than before.

Goroutine dump is extremely small -- looks like you're only serving a small handful of requests, but at least one of those requests is causing your server to spiral:

```
(pprof) top
Showing nodes accounting for 3.31GB, 100% of 3.32GB total
Dropped 13 nodes (cum <= 0.02GB)
Showing top 10 nodes out of 17
      flat  flat%   sum%        cum   cum%
    3.31GB   100%   100%     3.31GB   100%  bytes.growSlice
         0     0%   100%     3.31GB   100%  bytes.(*Buffer).ReadFrom
         0     0%   100%     3.31GB   100%  bytes.(*Buffer).grow
         0     0%   100%     3.31GB 99.91%  github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).ServeHTTP
         0     0%   100%     3.31GB   100%  github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).enforcementHandler
         0     0%   100%     3.31GB   100%  github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Server).wrapPrimaryRoute.func1
         0     0%   100%     3.31GB   100%  github.com/caddyserver/caddy/v2/modules/caddyhttp.(*Subroute).ServeHTTP
         0     0%   100%     3.31GB   100%  github.com/caddyserver/caddy/v2/modules/caddyhttp.HandlerFunc.ServeHTTP
         0     0%   100%     3.31GB   100%  github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapMiddleware.func1.1
         0     0%   100%     3.31GB   100%  github.com/caddyserver/caddy/v2/modules/caddyhttp.wrapRoute.func1.1
```

Something is buffering wildly.

Can you please do another go at this, but:

- Enable debug and access logs? Put `debug` in the global options at the top, and then `log` in all of your site blocks.
- Do you think you could also grab the file that shows the "full goroutine stack dump" goroutines just before a crash? It's at the URI `/debug/pprof/goroutine?debug=2`.

What kinds of requests is this server getting? Are clients uploading or downloading large files? What are the headers of the requests like? If you could post the unredacted logs here that would be extremely helpful :blush: Thank you!
The reverse proxy is buffering the body... (click this image to view large, if it doesn't show up)

![profile001](https://user-images.githubusercontent.com/1128849/218149437-18b43d54-18dd-4e5c-9164-f67c84f4eb57.svg)

Here's the relevant code, I think:

https://github.com/caddyserver/caddy/blob/90798f3eea6b7a219a9bb55f680919c0504263e3/modules/caddyhttp/reverseproxy/reverseproxy.go#L617-L628

These must be chunked requests...
Ok, culprit is this PR here: https://github.com/caddyserver/caddy/pull/5289

@u5surf Would you be able to help look into this? We will likely need to release a hotfix in v2.6.4 for this.

(This is also my oversight in code review, as we should not be buffering chunked requests. The reason they are chunked is because they are large. They should not be buffered.)

Edit: Wow, I just noticed that @mohammed90 caught it hours before I did. Sorry that slipped by my scrolling. (The GitHub app is... a bit janky with comments. I'm on my desktop now.) Thank you Mohammed!
Are more detailed logs still needed? The earliest I could look into the necessary configuration changes to collect them would be on next Monday.
@GerritKopp Nope, sorry -- I should have let you know that I think we have enough info now for a hotfix.
No problem. Looking forward for the fix. Thanks!

Fix patch:
diff --git a/modules/caddyhttp/reverseproxy/caddyfile.go b/modules/caddyhttp/reverseproxy/caddyfile.go
index cd9b77cd378..1211188d677 100644
--- a/modules/caddyhttp/reverseproxy/caddyfile.go
+++ b/modules/caddyhttp/reverseproxy/caddyfile.go
@@ -521,19 +521,39 @@ func (h *Handler) UnmarshalCaddyfile(d *caddyfile.Dispenser) error {
 					h.FlushInterval = caddy.Duration(dur)
 				}
 
-			case "buffer_requests":
+			case "request_buffers", "response_buffers":
+				subdir := d.Val()
+				if !d.NextArg() {
+					return d.ArgErr()
+				}
+				size, err := humanize.ParseBytes(d.Val())
+				if err != nil {
+					return d.Errf("invalid byte size '%s': %v", d.Val(), err)
+				}
 				if d.NextArg() {
 					return d.ArgErr()
 				}
-				h.BufferRequests = true
+				if subdir == "request_buffers" {
+					h.RequestBuffers = int64(size)
+				} else if subdir == "response_buffers" {
+					h.ResponseBuffers = int64(size)
 
-			case "buffer_responses":
+				}
+
+			// TODO: These three properties are deprecated; remove them sometime after v2.6.4
+			case "buffer_requests": // TODO: deprecated
 				if d.NextArg() {
 					return d.ArgErr()
 				}
-				h.BufferResponses = true
-
-			case "max_buffer_size":
+				caddy.Log().Named("config.adapter.caddyfile").Warn("DEPRECATED: buffer_requests: use request_buffers instead (with a maximum buffer size)")
+				h.DeprecatedBufferRequests = true
+			case "buffer_responses": // TODO: deprecated
+				if d.NextArg() {
+					return d.ArgErr()
+				}
+				caddy.Log().Named("config.adapter.caddyfile").Warn("DEPRECATED: buffer_responses: use response_buffers instead (with a maximum buffer size)")
+				h.DeprecatedBufferResponses = true
+			case "max_buffer_size": // TODO: deprecated
 				if !d.NextArg() {
 					return d.ArgErr()
 				}
@@ -544,7 +564,8 @@ func (h *Handler) UnmarshalCaddyfile(d *caddyfile.Dispenser) error {
 				if d.NextArg() {
 					return d.ArgErr()
 				}
-				h.MaxBufferSize = int64(size)
+				caddy.Log().Named("config.adapter.caddyfile").Warn("DEPRECATED: max_buffer_size: use request_buffers and/or response_buffers instead (with maximum buffer sizes)")
+				h.DeprecatedMaxBufferSize = int64(size)
 
 			case "trusted_proxies":
 				for d.NextArg() {
diff --git a/modules/caddyhttp/reverseproxy/reverseproxy.go b/modules/caddyhttp/reverseproxy/reverseproxy.go
index 88d98e82739..1449785fd45 100644
--- a/modules/caddyhttp/reverseproxy/reverseproxy.go
+++ b/modules/caddyhttp/reverseproxy/reverseproxy.go
@@ -136,21 +136,27 @@ type Handler struct {
 	// are also set implicitly.
 	Headers *headers.Handler `json:"headers,omitempty"`
 
-	// If true, the entire request body will be read and buffered
-	// in memory before being proxied to the backend. This should
-	// be avoided if at all possible for performance reasons, but
-	// could be useful if the backend is intolerant of read latency.
-	BufferRequests bool `json:"buffer_requests,omitempty"`
-
-	// If true, the entire response body will be read and buffered
-	// in memory before being proxied to the client. This should
-	// be avoided if at all possible for performance reasons, but
-	// could be useful if the backend has tighter memory constraints.
-	BufferResponses bool `json:"buffer_responses,omitempty"`
+	// DEPRECATED: Do not use; will be removed. See request_buffers instead.
+	DeprecatedBufferRequests bool `json:"buffer_requests,omitempty"`
+
+	// DEPRECATED: Do not use; will be removed. See response_buffers instead.
+	DeprecatedBufferResponses bool `json:"buffer_responses,omitempty"`
+
+	// DEPRECATED: Do not use; will be removed. See request_buffers and response_buffers instead.
+	DeprecatedMaxBufferSize int64 `json:"max_buffer_size,omitempty"`
+
+	// If nonzero, the entire request body up to this size will be read
+	// and buffered in memory before being proxied to the backend. This
+	// should be avoided if at all possible for performance reasons, but
+	// could be useful if the backend is intolerant of read latency or
+	// chunked encodings.
+	RequestBuffers int64 `json:"request_buffers,omitempty"`
 
-	// If body buffering is enabled, the maximum size of the buffers
-	// used for the requests and responses (in bytes).
-	MaxBufferSize int64 `json:"max_buffer_size,omitempty"`
+	// If nonzero, the entire response body up to this size will be read
+	// and buffered in memory before being proxied to the client. This
+	// should be avoided if at all possible for performance reasons, but
+	// could be useful if the backend has tighter memory constraints.
+	ResponseBuffers int64 `json:"response_buffers,omitempty"`
 
 	// If configured, rewrites the copy of the upstream request.
 	// Allows changing the request method and URI (path and query).
@@ -221,11 +227,28 @@ func (h *Handler) Provision(ctx caddy.Context) error {
 	h.connections = make(map[io.ReadWriteCloser]openConnection)
 	h.connectionsMu = new(sync.Mutex)
 
+	// TODO: remove deprecated fields sometime after v2.6.4
+	if h.DeprecatedBufferRequests {
+		h.logger.Warn("DEPRECATED: buffer_requests: this property will be removed soon; use request_buffers instead (and set a maximum buffer size)")
+	}
+	if h.DeprecatedBufferResponses {
+		h.logger.Warn("DEPRECATED: buffer_responses: this property will be removed soon; use response_buffers instead (and set a maximum buffer size)")
+	}
+	if h.DeprecatedMaxBufferSize != 0 {
+		h.logger.Warn("DEPRECATED: max_buffer_size: this property will be removed soon; use request_buffers and/or response_buffers instead (and set maximum buffer sizes)")
+	}
+
+	// warn about unsafe buffering config
+	if h.RequestBuffers == -1 || h.ResponseBuffers == -1 {
+		h.logger.Warn("UNLIMITED BUFFERING: buffering is enabled without any cap on buffer size, which can result in OOM crashes")
+	}
+
 	// verify SRV compatibility - TODO: LookupSRV deprecated; will be removed
 	for i, v := range h.Upstreams {
 		if v.LookupSRV == "" {
 			continue
 		}
+		h.logger.Warn("DEPRECATED: lookup_srv: will be removed in a near-future version of Caddy; use the http.reverse_proxy.upstreams.srv module instead")
 		if h.HealthChecks != nil && h.HealthChecks.Active != nil {
 			return fmt.Errorf(`upstream: lookup_srv is incompatible with active health checks: %d: {"dial": %q, "lookup_srv": %q}`, i, v.Dial, v.LookupSRV)
 		}
@@ -622,9 +645,8 @@ func (h Handler) prepareRequest(req *http.Request, repl *caddy.Replacer) (*http.
 	// attacks, so it is strongly recommended to only use this
 	// feature if absolutely required, if read timeouts are
 	// set, and if body size is limited
-	if (h.BufferRequests || isChunkedRequest(req)) && req.Body != nil {
-		req.Body, req.ContentLength = h.bufferedBody(req.Body)
-		req.Header.Set("Content-Length", strconv.FormatInt(req.ContentLength, 10))
+	if h.RequestBuffers != 0 && req.Body != nil {
+		req.Body, _ = h.bufferedBody(req.Body, h.RequestBuffers)
 	}
 
 	if req.ContentLength == 0 {
@@ -852,8 +874,8 @@ func (h *Handler) reverseProxy(rw http.ResponseWriter, req *http.Request, origRe
 	}
 
 	// if enabled, buffer the response body
-	if h.BufferResponses {
-		res.Body, _ = h.bufferedBody(res.Body)
+	if h.ResponseBuffers != 0 {
+		res.Body, _ = h.bufferedBody(res.Body, h.ResponseBuffers)
 	}
 
 	// see if any response handler is configured for this response from the backend
@@ -1122,15 +1144,20 @@ func (h Handler) provisionUpstream(upstream *Upstream) {
 	}
 }
 
-// bufferedBody reads originalBody into a buffer, then returns a reader for the buffer.
-// Always close the return value when done with it, just like if it was the original body!
-func (h Handler) bufferedBody(originalBody io.ReadCloser) (io.ReadCloser, int64) {
+// bufferedBody reads originalBody into a buffer with maximum size of limit (-1 for unlimited),
+// then returns a reader for the buffer along with how many bytes were buffered. Always close
+// the return value when done with it, just like if it was the original body! If limit is 0
+// (which it shouldn't be), this function returns its input; i.e. is a no-op, for safety.
+func (h Handler) bufferedBody(originalBody io.ReadCloser, limit int64) (io.ReadCloser, int64) {
+	if limit == 0 {
+		return originalBody, 0
+	}
 	var written int64
 	buf := bufPool.Get().(*bytes.Buffer)
 	buf.Reset()
-	if h.MaxBufferSize > 0 {
-		n, err := io.CopyN(buf, originalBody, h.MaxBufferSize)
-		if err != nil || n == h.MaxBufferSize {
+	if limit > 0 {
+		n, err := io.CopyN(buf, originalBody, limit)
+		if err != nil || n == limit {
 			return bodyReadCloser{
 				Reader: io.MultiReader(buf, originalBody),
 				buf:    buf,
@@ -1147,15 +1174,6 @@ func (h Handler) bufferedBody(originalBody io.ReadCloser) (io.ReadCloser, int64)
 	}, written
 }
 
-func isChunkedRequest(req *http.Request) bool {
-	for _, transferEncoding := range req.TransferEncoding {
-		if transferEncoding == "chunked" {
-			return true
-		}
-	}
-	return false
-}
-
 // cloneRequest makes a semi-deep clone of origReq.
 //
 // Most of this code is borrowed from the Go stdlib reverse proxy,


Test patch: