Memory cannot be released when receiving files in form-data

[20164930]

Describe the bug

I created a handler to receive files uploaded by clients. In the handler, I used the ParseMultipartForm function to set the maximum memory, and used FormFile to receive files and write them locally. However, during the debugging process, I found that the memory occupied by the Buffer could not be released. The strange thing is that this doesn't happen when I create an http server using net/http, I'm not sure if this problem is related to go-zero.

To Reproduce

1. The code is

  func main() {
	go func() {
		http.ListenAndServe("0.0.0.0:8000", nil)
	}()
	
	var restConf rest.RestConf
	conf.MustLoad("src/init.yaml", &restConf)
	s, err := rest.NewServer(restConf)
	if err != nil {
		log.Fatal(err)
		return
	}

	s.AddRoute(rest.Route{
		Method:  http.MethodPost,
		Path:    "/upload",
		Handler: upload,
	})
	defer s.Stop()
	s.Start()

	//http.HandleFunc("/upload", upload)
	//http.ListenAndServe("0.0.0.0:8888", nil)
}

func upload(w http.ResponseWriter, request *http.Request) {
	if err := request.ParseMultipartForm(32 << 20); err != nil {
		...
	}
	defer request.MultipartForm.RemoveAll()
	file, header, err := request.FormFile("file")
	if err != nil {
		...
	}
	defer file.Close()
	dst, err := os.Create(header.Filename)
	if err != nil {
		...
	}
	defer dst.Close()

	_, err = io.Copy(dst, file)
	if err != nil {
		...
	}
}
   

2. The error is

The memory allocation analyzed by pprof is as follows:

Memory allocation when using net/http is as follows:

Expected behavior Please confirm if this problem is related to go-zero, and how can I receive a large file using less memory?

Screenshots If applicable, add screenshots to help explain your problem.

Environments (please complete the following information):

• OS: windows10 & centos7
• go-zero version: 1.5.5

More description Add any other context about the problem here.

[20164930]

The iox.DupReadCloser() function is called in the LogHandler() function in the rest/handler/loghandler.go file,The content of this function is:

// DupReadCloser returns two io.ReadCloser that read from the first will be written to the second.
// The first returned reader needs to be read first, because the content
// read from it will be written to the underlying buffer of the second reader.
func DupReadCloser(reader io.ReadCloser) (io.ReadCloser, io.ReadCloser) {
	var buf bytes.Buffer
	tee := io.TeeReader(reader, &buf)
	return ioutil.NopCloser(tee), ioutil.NopCloser(&buf)
}

This function consumes a lot of memory.

[kevwan]

I profiled the code in this issue, didn't find memory leak problem.

I guess you're checking alloc_space, but I think you wanted to check inuse_space.

Please double check and let me know if any problem.

Thanks!

[20164930]

I'm sure I'm checking the memory in use：

$ go tool pprof --inuse_space http://127.0.0.1:8888/debug/pprof/heap
Fetching profile over HTTP from http://127.0.0.1:8888/debug/pprof/heap
Saved profile in C:\Users\User\pprof\pprof.___1go_build_main_go.exe.alloc_objects.alloc_space.inuse_objects.inuse_space.005.pb.gz
File: ___1go_build_main_go.exe
Build ID: C:\Users\User\AppData\Local\Temp\GoLand\___1go_build_main_go.exe2023-11-07 10:05:01.6110518 +0800 CST
Type: inuse_space
Time: Nov 7, 2023 at 10:13am (CST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) top
Showing nodes accounting for 388MB, 99.87% of 388.50MB total
Dropped 10 nodes (cum <= 1.94MB)
Showing top 10 nodes out of 24
      flat  flat%   sum%        cum   cum%
     388MB 99.87% 99.87%      388MB 99.87%  bytes.growSlice
         0     0% 99.87%      384MB 98.84%  bufio.(*Reader).Peek
         0     0% 99.87%      384MB 98.84%  bufio.(*Reader).fill
         0     0% 99.87%        4MB  1.03%  bytes.(*Buffer).ReadFrom
         0     0% 99.87%      384MB 98.84%  bytes.(*Buffer).Write
         0     0% 99.87%      388MB 99.87%  bytes.(*Buffer).grow
         0     0% 99.87%      388MB 99.87%  github.com/zeromicro/go-zero/rest/handler.(*timeoutHandler).ServeHTTP.func1
         0     0% 99.87%      388MB 99.87%  github.com/zeromicro/go-zero/rest/handler.GunzipHandler.func1
         0     0% 99.87%      388MB 99.87%  github.com/zeromicro/go-zero/rest/handler.MaxBytesHandler.func2.1
         0     0% 99.87%      388MB 99.87%  github.com/zeromicro/go-zero/rest/handler.MetricHandler.func1.1

traces:

(pprof)  traces bytes.growSlice
File: ___1go_build_main_go.exe
Build ID: C:\Users\User\AppData\Local\Temp\GoLand\___1go_build_main_go.exe2023-11-07 10:05:01.6110518 +0800 CST
Type: inuse_space
Time: Nov 7, 2023 at 10:13am (CST)
-----------+-------------------------------------------------------
     bytes:  512MB
         0   bytes.growSlice
             bytes.(*Buffer).grow
             bytes.(*Buffer).Write
             io.(*teeReader).Read
             mime/multipart.(*stickyErrorReader).Read
             bufio.(*Reader).fill
             bufio.(*Reader).Peek
             mime/multipart.partReader.Read
             mime/multipart.(*Part).Read
             io.copyBuffer
             io.CopyBuffer
             mime/multipart.(*Reader).readForm
             mime/multipart.(*Reader).ReadForm (inline)
             net/http.(*Request).ParseMultipartForm
             main.upload
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.GunzipHandler.func1
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.MaxBytesHandler.func2.1
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.MetricHandler.func1.1
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.RecoverHandler.func1
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.(*timeoutHandler).ServeHTTP.func1
-----------+-------------------------------------------------------
     bytes:  256MB
     256MB   bytes.growSlice
             bytes.(*Buffer).grow
             bytes.(*Buffer).Write
             io.(*teeReader).Read
             mime/multipart.(*stickyErrorReader).Read
             bufio.(*Reader).fill
             bufio.(*Reader).Peek
             mime/multipart.partReader.Read
             mime/multipart.(*Part).Read
             io.copyBuffer
             io.CopyBuffer
             mime/multipart.(*Reader).readForm
             mime/multipart.(*Reader).ReadForm (inline)
             net/http.(*Request).ParseMultipartForm
             main.upload
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.GunzipHandler.func1
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.MaxBytesHandler.func2.1
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.MetricHandler.func1.1
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.RecoverHandler.func1
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.(*timeoutHandler).ServeHTTP.func1
-----------+-------------------------------------------------------
     bytes:  128MB
     128MB   bytes.growSlice
             bytes.(*Buffer).grow
             bytes.(*Buffer).Write
             io.(*teeReader).Read
             mime/multipart.(*stickyErrorReader).Read
             bufio.(*Reader).fill
             bufio.(*Reader).Peek
             mime/multipart.partReader.Read
             mime/multipart.(*Part).Read
             io.copyBuffer
             io.CopyBuffer
             mime/multipart.(*Reader).readForm
             mime/multipart.(*Reader).ReadForm (inline)
             net/http.(*Request).ParseMultipartForm
             main.upload
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.GunzipHandler.func1
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.MaxBytesHandler.func2.1
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.MetricHandler.func1.1
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/rest/handler.RecoverHandler.func1
             net/http.HandlerFunc.ServeHTTP
             github.com/zeromicro/go-zero/re

According to my testing, there are actually two problems:

1. The memory used during the upload process should not exceed 32<<20, but it actually exceeds
2. After the upload is completed, it will take a few minutes for the memory to be recycled instead of being released immediately.

I suggest you observe it during the upload process or immediately after the upload is completed. In addition to pprof, you can also use the Windows Resource Monitor or the Linux command line to observe the memory changes of the process.

[haobinc]

i meet this problem too!

[Luo-Yihang]

@kevwan I can reproduce the issue. Specifically, my investigation revealed that the ParseMultipartForm function in go-zero is causing memory leaks and even unresolved temporary file issues when the actual file size exceeds the maxMemory parameter set in 'ParseMultipartForm'. This issue can be validated through go-zero official example (Please try to upload a large files, e.g. 2gb to better reproduce the bug), where I was able to reproduce the memory leak when utilizing ParseMultipartForm. Additionally, I conducted tests on an isolated Go file, which demonstrated normal functionality without encountering any issues.