🐛 fix issue with strange messages in the http body when max request

size reached.

Signed-off-by: Valery Piashchynski <[email protected]>

27 files changed, 158 insertions, 83 deletions

diff --git a/plugins/http/handler.go b/plugins/http/handler.go
index 0e7481b5..11d9b827 100644
--- a/plugins/http/handler.go
+++ b/plugins/http/handler.go
@@ -8,7 +8,6 @@ import (
 	"sync"
 	"time"
 
-	"github.com/hashicorp/go-multierror"
 	"github.com/spiral/errors"
 	"github.com/spiral/roadrunner/v2/pkg/events"
 	"github.com/spiral/roadrunner/v2/pkg/pool"
@@ -95,15 +94,37 @@ func (h *Handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 
 	// validating request size
 	if h.maxRequestSize != 0 {
-		err := h.maxSize(w, r, start, op)
-		if err != nil {
+		const op = errors.Op("http_handler_max_size")
+		if length := r.Header.Get("content-length"); length != "" {
+			// try to parse the value from the `content-length` header
+			size, err := strconv.ParseInt(length, 10, 64)
+			if err != nil {
+				// if got an error while parsing -> assign 500 code to the writer and return
+				http.Error(w, errors.E(op, err).Error(), 500)
+				h.sendEvent(ErrorEvent{Request: r, Error: errors.E(op, errors.Str("error while parsing value from the `content-length` header")), start: start, elapsed: time.Since(start)})
+				return
+			}
+
+			if size > int64(h.maxRequestSize) {
+				http.Error(w, errors.E(op, errors.Str("request body max size is exceeded")).Error(), 500)
+			}
+
+			h.sendEvent(ErrorEvent{Request: r, Error: errors.E(op, errors.Str("request body max size is exceeded")), start: start, elapsed: time.Since(start)})
 			return
 		}
 	}
 
 	req, err := NewRequest(r, h.uploads)
 	if err != nil {
-		h.handleError(w, r, err, start)
+		// if pipe is broken, there is no sense to write the header
+		// in this case we just report about error
+		if err == errEPIPE {
+			h.sendEvent(ErrorEvent{Request: r, Error: err, start: start, elapsed: time.Since(start)})
+			return
+		}
+
+		http.Error(w, errors.E(op, err).Error(), 500)
+		h.sendEvent(ErrorEvent{Request: r, Error: errors.E(op, err), start: start, elapsed: time.Since(start)})
 		return
 	}
 
@@ -115,73 +136,40 @@ func (h *Handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 
 	p, err := req.Payload()
 	if err != nil {
-		h.handleError(w, r, err, start)
+		http.Error(w, errors.E(op, err).Error(), 500)
+		h.sendEvent(ErrorEvent{Request: r, Error: errors.E(op, err), start: start, elapsed: time.Since(start)})
 		return
 	}
 
 	rsp, err := h.pool.Exec(p)
 	if err != nil {
-		h.handleError(w, r, err, start)
+		http.Error(w, errors.E(op, err).Error(), 500)
+		h.sendEvent(ErrorEvent{Request: r, Error: errors.E(op, err), start: start, elapsed: time.Since(start)})
 		return
 	}
 
 	resp, err := NewResponse(rsp)
 	if err != nil {
-		h.handleError(w, r, err, start)
+		http.Error(w, errors.E(op, err).Error(), resp.Status)
+		h.sendEvent(ErrorEvent{Request: r, Error: errors.E(op, err), start: start, elapsed: time.Since(start)})
 		return
 	}
 
 	h.handleResponse(req, resp, start)
 	err = resp.Write(w)
 	if err != nil {
-		h.handleError(w, r, err, start)
-	}
-}
-
-func (h *Handler) maxSize(w http.ResponseWriter, r *http.Request, start time.Time, op errors.Op) error {
-	if length := r.Header.Get("content-length"); length != "" {
-		if size, err := strconv.ParseInt(length, 10, 64); err != nil {
-			h.handleError(w, r, err, start)
-			return err
-		} else if size > int64(h.maxRequestSize) {
-			h.handleError(w, r, errors.E(op, errors.Str("request body max size is exceeded")), start)
-			return err
-		}
-	}
-	return nil
-}
-
-// handleError sends error.
-func (h *Handler) handleError(w http.ResponseWriter, r *http.Request, err error, start time.Time) {
-	h.mul.Lock()
-	defer h.mul.Unlock()
-	// if pipe is broken, there is no sense to write the header
-	// in this case we just report about error
-	if err == errEPIPE {
-		h.throw(ErrorEvent{Request: r, Error: err, start: start, elapsed: time.Since(start)})
-		return
-	}
-	err = multierror.Append(err)
-	// ResponseWriter is ok, write the error code
-	w.WriteHeader(500)
-	_, err2 := w.Write([]byte(err.Error()))
-	// error during the writing to the ResponseWriter
-	if err2 != nil {
-		err = multierror.Append(err2, err)
-		// concat original error with ResponseWriter error
-		h.throw(ErrorEvent{Request: r, Error: errors.E(err), start: start, elapsed: time.Since(start)})
-		return
+		http.Error(w, errors.E(op, err).Error(), 500)
+		h.sendEvent(ErrorEvent{Request: r, Error: errors.E(op, err), start: start, elapsed: time.Since(start)})
 	}
-	h.throw(ErrorEvent{Request: r, Error: err, start: start, elapsed: time.Since(start)})
 }
 
 // handleResponse triggers response event.
 func (h *Handler) handleResponse(req *Request, resp *Response, start time.Time) {
-	h.throw(ResponseEvent{Request: req, Response: resp, start: start, elapsed: time.Since(start)})
+	h.sendEvent(ResponseEvent{Request: req, Response: resp, start: start, elapsed: time.Since(start)})
 }
 
-// throw invokes event handler if any.
-func (h *Handler) throw(event interface{}) {
+// sendEvent invokes event handler if any.
+func (h *Handler) sendEvent(event interface{}) {
 	if h.lsn != nil {
 		h.lsn(event)
 	}
diff --git a/plugins/http/plugin.go b/plugins/http/plugin.go
index 69d13bc8..82cf76ed 100644
--- a/plugins/http/plugin.go
+++ b/plugins/http/plugin.go
@@ -326,7 +326,7 @@ func (s *Plugin) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	}
 
 	r = attributes.Init(r)
-	// protect the case, when user send Reset and we are replacing handler with pool
+	// protect the case, when user sendEvent Reset and we are replacing handler with pool
 	s.RLock()
 	s.handler.ServeHTTP(w, r)
 	s.RUnlock()
diff --git a/tests/plugins/gzip/configs/.rr-http-middlewareNotExist.yaml b/tests/plugins/gzip/configs/.rr-http-middlewareNotExist.yaml
index b900ff30..9e5b9c60 100644
--- a/tests/plugins/gzip/configs/.rr-http-middlewareNotExist.yaml
+++ b/tests/plugins/gzip/configs/.rr-http-middlewareNotExist.yaml
@@ -8,7 +8,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: 127.0.0.1:18103
   max_request_size: 1024
   middleware: [ "gzip", "foo" ]
diff --git a/tests/plugins/gzip/configs/.rr-http-withGzip.yaml b/tests/plugins/gzip/configs/.rr-http-withGzip.yaml
index dc12dc05..c67e207b 100644
--- a/tests/plugins/gzip/configs/.rr-http-withGzip.yaml
+++ b/tests/plugins/gzip/configs/.rr-http-withGzip.yaml
@@ -6,7 +6,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: 127.0.0.1:18953
   max_request_size: 1024
   middleware: [ "gzip" ]
diff --git a/tests/plugins/http/configs/.rr-big-req-size.yaml b/tests/plugins/http/configs/.rr-big-req-size.yaml
new file mode 100644
index 00000000..574b3393
--- /dev/null
+++ b/tests/plugins/http/configs/.rr-big-req-size.yaml
@@ -0,0 +1,21 @@
+rpc:
+  listen: tcp://127.0.0.1:6001
+
+server:
+  command: "php ../../http/client.php echo pipes"
+
+http:
+  address: 127.0.0.1:10085
+  max_request_size: 1
+  middleware: [ "" ]
+  uploads:
+    forbid: [ ".php", ".exe", ".bat" ]
+  trusted_subnets: [ "10.0.0.0/8", "127.0.0.0/8", "172.16.0.0/12", "192.168.0.0/16", "::1/128", "fc00::/7", "fe80::/10" ]
+  pool:
+    num_workers: 2
+    max_jobs: 0
+    allocate_timeout: 60s
+    destroy_timeout: 60s
+logs:
+  mode: development
+  level: error
\ No newline at end of file
diff --git a/tests/plugins/http/configs/.rr-broken-pipes.yaml b/tests/plugins/http/configs/.rr-broken-pipes.yaml
index 9b7d2d0b..703f9431 100644
--- a/tests/plugins/http/configs/.rr-broken-pipes.yaml
+++ b/tests/plugins/http/configs/.rr-broken-pipes.yaml
@@ -11,7 +11,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: 127.0.0.1:12384
   max_request_size: 1024
   middleware: [ "" ]
diff --git a/tests/plugins/http/configs/.rr-env.yaml b/tests/plugins/http/configs/.rr-env.yaml
index e6b00b69..99358b04 100644
--- a/tests/plugins/http/configs/.rr-env.yaml
+++ b/tests/plugins/http/configs/.rr-env.yaml
@@ -11,7 +11,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: 127.0.0.1:12084
   max_request_size: 1024
   middleware: [ "" ]
diff --git a/tests/plugins/http/configs/.rr-fcgi-reqUri.yaml b/tests/plugins/http/configs/.rr-fcgi-reqUri.yaml
index ab42f4fc..28c70c6f 100644
--- a/tests/plugins/http/configs/.rr-fcgi-reqUri.yaml
+++ b/tests/plugins/http/configs/.rr-fcgi-reqUri.yaml
@@ -8,7 +8,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: :8082
   max_request_size: 1024
   middleware: [ "" ]
diff --git a/tests/plugins/http/configs/.rr-fcgi.yaml b/tests/plugins/http/configs/.rr-fcgi.yaml
index bd5d01bd..c749e42b 100644
--- a/tests/plugins/http/configs/.rr-fcgi.yaml
+++ b/tests/plugins/http/configs/.rr-fcgi.yaml
@@ -8,7 +8,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: :8081
   max_request_size: 1024
   middleware: [ "" ]
diff --git a/tests/plugins/http/configs/.rr-h2c.yaml b/tests/plugins/http/configs/.rr-h2c.yaml
index bd610bb0..796ad307 100644
--- a/tests/plugins/http/configs/.rr-h2c.yaml
+++ b/tests/plugins/http/configs/.rr-h2c.yaml
@@ -8,7 +8,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: :8083
   max_request_size: 1024
   middleware: [ "" ]
diff --git a/tests/plugins/http/configs/.rr-http-supervised-pool.yaml b/tests/plugins/http/configs/.rr-http-supervised-pool.yaml
index e92ce051..e0c38c12 100644
--- a/tests/plugins/http/configs/.rr-http-supervised-pool.yaml
+++ b/tests/plugins/http/configs/.rr-http-supervised-pool.yaml
@@ -10,7 +10,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: 127.0.0.1:18888
   max_request_size: 1024
   middleware: [ "" ]
diff --git a/tests/plugins/http/configs/.rr-http.yaml b/tests/plugins/http/configs/.rr-http.yaml
index 184a353c..c95bc049 100644
--- a/tests/plugins/http/configs/.rr-http.yaml
+++ b/tests/plugins/http/configs/.rr-http.yaml
@@ -11,7 +11,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: 127.0.0.1:18903
   max_request_size: 1024
   middleware: [ "pluginMiddleware", "pluginMiddleware2" ]
diff --git a/tests/plugins/http/configs/.rr-init.yaml b/tests/plugins/http/configs/.rr-init.yaml
index 77132b43..1671c3c0 100644
--- a/tests/plugins/http/configs/.rr-init.yaml
+++ b/tests/plugins/http/configs/.rr-init.yaml
@@ -11,7 +11,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: 127.0.0.1:15395
   max_request_size: 1024
   middleware: [ "" ]
diff --git a/tests/plugins/http/configs/.rr-resetter.yaml b/tests/plugins/http/configs/.rr-resetter.yaml
index a1ef27d1..61b0e501 100644
--- a/tests/plugins/http/configs/.rr-resetter.yaml
+++ b/tests/plugins/http/configs/.rr-resetter.yaml
@@ -11,7 +11,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: 127.0.0.1:10084
   max_request_size: 1024
   middleware: [ "" ]
diff --git a/tests/plugins/http/configs/.rr-ssl-push.yaml b/tests/plugins/http/configs/.rr-ssl-push.yaml
index 11a8ddd3..3349575e 100644
--- a/tests/plugins/http/configs/.rr-ssl-push.yaml
+++ b/tests/plugins/http/configs/.rr-ssl-push.yaml
@@ -8,7 +8,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: :8086
   max_request_size: 1024
   middleware: [ "" ]
diff --git a/tests/plugins/http/configs/.rr-ssl-redirect.yaml b/tests/plugins/http/configs/.rr-ssl-redirect.yaml
index e49a73ed..1d04963e 100644
--- a/tests/plugins/http/configs/.rr-ssl-redirect.yaml
+++ b/tests/plugins/http/configs/.rr-ssl-redirect.yaml
@@ -8,7 +8,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: :8087
   max_request_size: 1024
   middleware: [ "" ]
diff --git a/tests/plugins/http/http_plugin_test.go b/tests/plugins/http/http_plugin_test.go
index d136b437..cf22a9cd 100644
--- a/tests/plugins/http/http_plugin_test.go
+++ b/tests/plugins/http/http_plugin_test.go
@@ -2,6 +2,7 @@ package http
 
 import (
 	"bytes"
+	"crypto/rand"
 	"crypto/tls"
 	"fmt"
 	"io/ioutil"
@@ -1415,23 +1416,21 @@ server:
   command: "%s"
   user: ""
   group: ""
-  env:
-    "RR_HTTP": "true"
   relay: "pipes"
-  relayTimeout: "20s"
+  relay_timeout: "20s"
 
 http:
   address: 127.0.0.1:%s
-  maxRequestSize: 1024
+  max_request_size: 1024
   middleware: [ "" ]
   uploads:
     forbid: [ ".php", ".exe", ".bat" ]
-  trustedSubnets: [ "10.0.0.0/8", "127.0.0.0/8", "172.16.0.0/12", "192.168.0.0/16", "::1/128", "fc00::/7", "fe80::/10" ]
+  trusted_subnets: [ "10.0.0.0/8", "127.0.0.0/8", "172.16.0.0/12", "192.168.0.0/16", "::1/128", "fc00::/7", "fe80::/10" ]
   pool:
-    numWorkers: 2
-    maxJobs: 0
-    allocateTimeout: 60s
-    destroyTimeout: 60s
+    num_workers: 2
+    max_jobs: 0
+    allocate_timeout: 60s
+    destroy_timeout: 60s
 
   ssl:
     address: %s
@@ -1444,9 +1443,98 @@ http:
   http2:
     enabled: %s
     h2c: false
-    maxConcurrentStreams: 128
+    max_concurrent_streams: 128
 logs:
   mode: development
   level: error
 `, rpcPort, command, httpPort, sslAddress, redirect, fcgiPort, http2Enabled))
 }
+
+func TestHTTPBigRequestSize(t *testing.T) {
+	cont, err := endure.NewContainer(nil, endure.SetLogLevel(endure.ErrorLevel))
+	assert.NoError(t, err)
+
+	cfg := &config.Viper{
+		Path:   "configs/.rr-big-req-size.yaml",
+		Prefix: "rr",
+		Type:   "yaml",
+	}
+
+	err = cont.RegisterAll(
+		cfg,
+		&logger.ZapLogger{},
+		&server.Plugin{},
+		&httpPlugin.Plugin{},
+	)
+	assert.NoError(t, err)
+
+	err = cont.Init()
+	if err != nil {
+		t.Fatal(err)
+	}
+
+	ch, err := cont.Serve()
+	assert.NoError(t, err)
+
+	sig := make(chan os.Signal, 1)
+	signal.Notify(sig, os.Interrupt, syscall.SIGINT, syscall.SIGTERM)
+
+	wg := &sync.WaitGroup{}
+	wg.Add(1)
+
+	stopCh := make(chan struct{}, 1)
+
+	go func() {
+		defer wg.Done()
+		for {
+			select {
+			case e := <-ch:
+				assert.Fail(t, "error", e.Error.Error())
+				err = cont.Stop()
+				if err != nil {
+					assert.FailNow(t, "error", err.Error())
+				}
+			case <-sig:
+				err = cont.Stop()
+				if err != nil {
+					assert.FailNow(t, "error", err.Error())
+				}
+				return
+			case <-stopCh:
+				// timeout
+				err = cont.Stop()
+				if err != nil {
+					assert.FailNow(t, "error", err.Error())
+				}
+				return
+			}
+		}
+	}()
+
+	t.Run("HTTPBigEcho10Mb", bigEchoHTTP)
+
+	stopCh <- struct{}{}
+	wg.Wait()
+}
+
+func bigEchoHTTP(t *testing.T) {
+	buf := make([]byte, 1024*1024*10)
+
+	_, err := rand.Read(buf)
+	assert.NoError(t, err)
+
+	bt := bytes.NewBuffer(buf)
+
+	req, err := http.NewRequest("GET", "http://localhost:10085?hello=world", bt)
+	assert.NoError(t, err)
+
+	r, err := http.DefaultClient.Do(req)
+	assert.NoError(t, err)
+	b, err := ioutil.ReadAll(r.Body)
+	assert.NoError(t, err)
+	assert.Equal(t, 500, r.StatusCode)
+	assert.Equal(t, "http_handler_max_size: request body max size is exceeded\n", string(b))
+
+	err = r.Body.Close()
+	assert.NoError(t, err)
+}
diff --git a/tests/plugins/logger/configs/.rr-no-logger2.yaml b/tests/plugins/logger/configs/.rr-no-logger2.yaml
index 1211b7ad..c68639bc 100644
--- a/tests/plugins/logger/configs/.rr-no-logger2.yaml
+++ b/tests/plugins/logger/configs/.rr-no-logger2.yaml
@@ -11,7 +11,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: 127.0.0.1:18945
   max_request_size: 1024
   pool:
diff --git a/tests/plugins/reload/configs/.rr-reload-2.yaml b/tests/plugins/reload/configs/.rr-reload-2.yaml
index 882ab628..3881d4d9 100644
--- a/tests/plugins/reload/configs/.rr-reload-2.yaml
+++ b/tests/plugins/reload/configs/.rr-reload-2.yaml
@@ -7,7 +7,6 @@ server:
   relay: pipes
   relay_timeout: 20s
 http:
-  debug: true
   address: '127.0.0.1:27388'
   max_request_size: 1024
   middleware:
diff --git a/tests/plugins/reload/configs/.rr-reload-3.yaml b/tests/plugins/reload/configs/.rr-reload-3.yaml
index 4f964609..cdd32d20 100644
--- a/tests/plugins/reload/configs/.rr-reload-3.yaml
+++ b/tests/plugins/reload/configs/.rr-reload-3.yaml
@@ -7,7 +7,6 @@ server:
   relay: pipes
   relay_timeout: 20s
 http:
-  debug: true
   address: '127.0.0.1:37388'
   max_request_size: 1024
   middleware:
diff --git a/tests/plugins/reload/configs/.rr-reload-4.yaml b/tests/plugins/reload/configs/.rr-reload-4.yaml
index 76966e49..c499ec90 100644
--- a/tests/plugins/reload/configs/.rr-reload-4.yaml
+++ b/tests/plugins/reload/configs/.rr-reload-4.yaml
@@ -7,7 +7,6 @@ server:
   relay: pipes
   relay_timeout: 20s
 http:
-  debug: true
   address: '127.0.0.1:22766'
   max_request_size: 1024
   middleware:
diff --git a/tests/plugins/reload/configs/.rr-reload.yaml b/tests/plugins/reload/configs/.rr-reload.yaml
index 5dfb1171..b68430ef 100644
--- a/tests/plugins/reload/configs/.rr-reload.yaml
+++ b/tests/plugins/reload/configs/.rr-reload.yaml
@@ -7,7 +7,6 @@ server:
   relay: pipes
   relay_timeout: 20s
 http:
-  debug: true
   address: '127.0.0.1:22388'
   max_request_size: 1024
   middleware:
diff --git a/tests/plugins/static/configs/.rr-http-static-disabled.yaml b/tests/plugins/static/configs/.rr-http-static-disabled.yaml
index 9f04b8a9..a85bc408 100644
--- a/tests/plugins/static/configs/.rr-http-static-disabled.yaml
+++ b/tests/plugins/static/configs/.rr-http-static-disabled.yaml
@@ -8,7 +8,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: 127.0.0.1:21234
   max_request_size: 1024
   middleware: [ "gzip" ]
diff --git a/tests/plugins/static/configs/.rr-http-static-files-disable.yaml b/tests/plugins/static/configs/.rr-http-static-files-disable.yaml
index 3d4d50b9..6ba47c91 100644
--- a/tests/plugins/static/configs/.rr-http-static-files-disable.yaml
+++ b/tests/plugins/static/configs/.rr-http-static-files-disable.yaml
@@ -8,7 +8,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: 127.0.0.1:45877
   max_request_size: 1024
   middleware: [ "gzip" ]
diff --git a/tests/plugins/static/configs/.rr-http-static-files.yaml b/tests/plugins/static/configs/.rr-http-static-files.yaml
index deb1f253..d6b3032e 100644
--- a/tests/plugins/static/configs/.rr-http-static-files.yaml
+++ b/tests/plugins/static/configs/.rr-http-static-files.yaml
@@ -8,7 +8,6 @@ server:
   relay_timeout: "20s"
 
 http:
-  debug: true
   address: 127.0.0.1:34653
   max_request_size: 1024
   middleware: [ "gzip", "static" ]
diff --git a/tests/plugins/checker/configs/.rr-checker-init.yaml b/tests/plugins/status/configs/.rr-status-init.yaml
index dca86efe..c791c10f 100755
--- a/tests/plugins/checker/configs/.rr-checker-init.yaml
+++ b/tests/plugins/status/configs/.rr-status-init.yaml
@@ -15,7 +15,6 @@ logs:
   mode: development
   level: error
 http:
-  debug: true
   address: 127.0.0.1:11933
   max_request_size: 1024
   middleware: [ "" ]
diff --git a/tests/plugins/checker/plugin_test.go b/tests/plugins/status/plugin_test.go
index 569e73a1..3330cb20 100644
--- a/tests/plugins/checker/plugin_test.go
+++ b/tests/plugins/status/plugin_test.go
@@ -1,4 +1,4 @@
-package checker
+package status
 
 import (
 	"io/ioutil"
@@ -28,7 +28,7 @@ func TestStatusHttp(t *testing.T) {
 	assert.NoError(t, err)
 
 	cfg := &config.Viper{
-		Path:   "configs/.rr-checker-init.yaml",
+		Path:   "configs/.rr-status-init.yaml",
 		Prefix: "rr",
 	}