return 504 instead of 404 for proxy type http request timeout (#4151)

.golangci.yml

@@ -86,12 +86,8 @@ linters-settings:
     severity: "low"
     confidence: "low"
     excludes:
-    - G102
-    - G112
-    - G306
     - G401
     - G402
-    - G404
     - G501
 
 issues:

Release.md

@@ -1 +1,3 @@
-### Features
+### Fixes
+
+* When an HTTP proxy request times out, it returns 504 instead of 404 now.

client/admin_api.go

@@ -253,7 +253,7 @@ func (svr *Service) apiPutConfig(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	if err := os.WriteFile(svr.configFilePath, body, 0o644); err != nil {
+	if err := os.WriteFile(svr.configFilePath, body, 0o600); err != nil {
 		res.Code = 500
 		res.Msg = fmt.Sprintf("write content to frpc config file error: %v", err)
 		log.Warnf("%s", res.Msg)

client/connector.go

@@ -24,7 +24,7 @@ import (
 	"sync"
 	"time"
 
-	libdial "github.com/fatedier/golib/net/dial"
+	libnet "github.com/fatedier/golib/net"
 	fmux "github.com/hashicorp/yamux"
 	quic "github.com/quic-go/quic-go"
 	"github.com/samber/lo"
@@ -169,44 +169,44 @@ func (c *defaultConnectorImpl) realConnect() (net.Conn, error) {
 		}
 	}
 
-	proxyType, addr, auth, err := libdial.ParseProxyURL(c.cfg.Transport.ProxyURL)
+	proxyType, addr, auth, err := libnet.ParseProxyURL(c.cfg.Transport.ProxyURL)
 	if err != nil {
 		xl.Errorf("fail to parse proxy url")
 		return nil, err
 	}
-	dialOptions := []libdial.DialOption{}
+	dialOptions := []libnet.DialOption{}
 	protocol := c.cfg.Transport.Protocol
 	switch protocol {
 	case "websocket":
 		protocol = "tcp"
-		dialOptions = append(dialOptions, libdial.WithAfterHook(libdial.AfterHook{Hook: netpkg.DialHookWebsocket(protocol, "")}))
-		dialOptions = append(dialOptions, libdial.WithAfterHook(libdial.AfterHook{
+		dialOptions = append(dialOptions, libnet.WithAfterHook(libnet.AfterHook{Hook: netpkg.DialHookWebsocket(protocol, "")}))
+		dialOptions = append(dialOptions, libnet.WithAfterHook(libnet.AfterHook{
 			Hook: netpkg.DialHookCustomTLSHeadByte(tlsConfig != nil, lo.FromPtr(c.cfg.Transport.TLS.DisableCustomTLSFirstByte)),
 		}))
-		dialOptions = append(dialOptions, libdial.WithTLSConfig(tlsConfig))
+		dialOptions = append(dialOptions, libnet.WithTLSConfig(tlsConfig))
 	case "wss":
 		protocol = "tcp"
-		dialOptions = append(dialOptions, libdial.WithTLSConfigAndPriority(100, tlsConfig))
+		dialOptions = append(dialOptions, libnet.WithTLSConfigAndPriority(100, tlsConfig))
 		// Make sure that if it is wss, the websocket hook is executed after the tls hook.
-		dialOptions = append(dialOptions, libdial.WithAfterHook(libdial.AfterHook{Hook: netpkg.DialHookWebsocket(protocol, tlsConfig.ServerName), Priority: 110}))
+		dialOptions = append(dialOptions, libnet.WithAfterHook(libnet.AfterHook{Hook: netpkg.DialHookWebsocket(protocol, tlsConfig.ServerName), Priority: 110}))
 	default:
-		dialOptions = append(dialOptions, libdial.WithAfterHook(libdial.AfterHook{
+		dialOptions = append(dialOptions, libnet.WithAfterHook(libnet.AfterHook{
 			Hook: netpkg.DialHookCustomTLSHeadByte(tlsConfig != nil, lo.FromPtr(c.cfg.Transport.TLS.DisableCustomTLSFirstByte)),
 		}))
-		dialOptions = append(dialOptions, libdial.WithTLSConfig(tlsConfig))
+		dialOptions = append(dialOptions, libnet.WithTLSConfig(tlsConfig))
 	}
 
 	if c.cfg.Transport.ConnectServerLocalIP != "" {
-		dialOptions = append(dialOptions, libdial.WithLocalAddr(c.cfg.Transport.ConnectServerLocalIP))
+		dialOptions = append(dialOptions, libnet.WithLocalAddr(c.cfg.Transport.ConnectServerLocalIP))
 	}
 	dialOptions = append(dialOptions,
-		libdial.WithProtocol(protocol),
-		libdial.WithTimeout(time.Duration(c.cfg.Transport.DialServerTimeout)*time.Second),
-		libdial.WithKeepAlive(time.Duration(c.cfg.Transport.DialServerKeepAlive)*time.Second),
-		libdial.WithProxy(proxyType, addr),
-		libdial.WithProxyAuth(auth),
+		libnet.WithProtocol(protocol),
+		libnet.WithTimeout(time.Duration(c.cfg.Transport.DialServerTimeout)*time.Second),
+		libnet.WithKeepAlive(time.Duration(c.cfg.Transport.DialServerKeepAlive)*time.Second),
+		libnet.WithProxy(proxyType, addr),
+		libnet.WithProxyAuth(auth),
 	)
-	conn, err := libdial.DialContext(
+	conn, err := libnet.DialContext(
 		c.ctx,
 		net.JoinHostPort(c.cfg.ServerAddr, strconv.Itoa(c.cfg.ServerPort)),
 		dialOptions...,

client/proxy/proxy.go

@@ -25,7 +25,7 @@ import (
 	"time"
 
 	libio "github.com/fatedier/golib/io"
-	libdial "github.com/fatedier/golib/net/dial"
+	libnet "github.com/fatedier/golib/net"
 	pp "github.com/pires/go-proxyproto"
 	"golang.org/x/time/rate"
 
@@ -197,9 +197,9 @@ func (pxy *BaseProxy) HandleTCPWorkConnection(workConn net.Conn, m *msg.StartWor
 		return
 	}
 
-	localConn, err := libdial.Dial(
+	localConn, err := libnet.Dial(
 		net.JoinHostPort(baseCfg.LocalIP, strconv.Itoa(baseCfg.LocalPort)),
-		libdial.WithTimeout(10*time.Second),
+		libnet.WithTimeout(10*time.Second),
 	)
 	if err != nil {
 		workConn.Close()

go.mod

@@ -5,7 +5,7 @@ go 1.22
 require (
 	github.com/armon/go-socks5 v0.0.0-20160902184237-e75332964ef5
 	github.com/coreos/go-oidc/v3 v3.10.0
-	github.com/fatedier/golib v0.4.3
+	github.com/fatedier/golib v0.5.0
 	github.com/google/uuid v1.6.0
 	github.com/gorilla/mux v1.8.1
 	github.com/gorilla/websocket v1.5.0

go.sum

@@ -24,8 +24,8 @@ github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSs
 github.com/envoyproxy/go-control-plane v0.9.0/go.mod h1:YTl/9mNaCwkRvm6d1a2C3ymFceY/DCBVvsKhRF0iEA4=
 github.com/envoyproxy/go-control-plane v0.9.4/go.mod h1:6rpuAdCZL397s3pYoYcLgu1mIlRU8Am5FuJP05cCM98=
 github.com/envoyproxy/protoc-gen-validate v0.1.0/go.mod h1:iSmxcyjqTsJpI2R4NaDN7+kN2VEUnK/pcBlmesArF7c=
-github.com/fatedier/golib v0.4.3 h1:eOcDBZauYqoNKwnJY9xWWa1pu7ff/JPZBizXeZOtj7k=
-github.com/fatedier/golib v0.4.3/go.mod h1:W6kIYkIFxHsTzbgqg5piCxIiDo4LzwgTY6R5W8l9NFQ=
+github.com/fatedier/golib v0.5.0 h1:hNcH7hgfIFqVWbP+YojCCAj4eO94pPf4dEF8lmq2jWs=
+github.com/fatedier/golib v0.5.0/go.mod h1:W6kIYkIFxHsTzbgqg5piCxIiDo4LzwgTY6R5W8l9NFQ=
 github.com/fatedier/yamux v0.0.0-20230628132301-7aca4898904d h1:ynk1ra0RUqDWQfvFi5KtMiSobkVQ3cNc0ODb8CfIETo=
 github.com/fatedier/yamux v0.0.0-20230628132301-7aca4898904d/go.mod h1:CtWFDAQgb7dxtzFs4tWbplKIe2jSi3+5vKbgIO0SLnQ=
 github.com/go-jose/go-jose/v4 v4.0.1 h1:QVEPDE3OluqXBQZDcnNvQrInro2h0e4eqNbnZSWqS6U=

pkg/plugin/client/http2https.go

@@ -19,11 +19,15 @@ package plugin
 import (
 	"crypto/tls"
 	"io"
+	stdlog "log"
 	"net"
 	"net/http"
 	"net/http/httputil"
 
+	"github.com/fatedier/golib/pool"
+
 	v1 "github.com/fatedier/frp/pkg/config/v1"
+	"github.com/fatedier/frp/pkg/util/log"
 	netpkg "github.com/fatedier/frp/pkg/util/net"
 )
 
@@ -68,6 +72,8 @@ func NewHTTP2HTTPSPlugin(options v1.ClientPluginOptions) (Plugin, error) {
 			}
 		},
 		Transport:  tr,
+		BufferPool: pool.NewBuffer(32 * 1024),
+		ErrorLog:   stdlog.New(log.NewWriteLogger(log.WarnLevel, 2), "", 0),
 	}
 
 	p.s = &http.Server{

pkg/plugin/client/http_proxy.go

@@ -55,6 +55,7 @@ func NewHTTPProxyPlugin(options v1.ClientPluginOptions) (Plugin, error) {
 
 	hp.s = &http.Server{
 		Handler:           hp,
+		ReadHeaderTimeout: 60 * time.Second,
 	}
 
 	go func() {

pkg/plugin/client/https2http.go

@@ -20,12 +20,17 @@ import (
 	"crypto/tls"
 	"fmt"
 	"io"
+	stdlog "log"
 	"net"
 	"net/http"
 	"net/http/httputil"
+	"time"
+
+	"github.com/fatedier/golib/pool"
 
 	v1 "github.com/fatedier/frp/pkg/config/v1"
 	"github.com/fatedier/frp/pkg/transport"
+	"github.com/fatedier/frp/pkg/util/log"
 	netpkg "github.com/fatedier/frp/pkg/util/net"
 )
 
@@ -63,10 +68,13 @@ func NewHTTPS2HTTPPlugin(options v1.ClientPluginOptions) (Plugin, error) {
 				req.Header.Set(k, v)
 			}
 		},
+		BufferPool: pool.NewBuffer(32 * 1024),
+		ErrorLog:   stdlog.New(log.NewWriteLogger(log.WarnLevel, 2), "", 0),
 	}
 
 	p.s = &http.Server{
 		Handler:           rp,
+		ReadHeaderTimeout: 60 * time.Second,
 	}
 
 	var (

pkg/plugin/client/https2https.go

@@ -20,12 +20,17 @@ import (
 	"crypto/tls"
 	"fmt"
 	"io"
+	stdlog "log"
 	"net"
 	"net/http"
 	"net/http/httputil"
+	"time"
+
+	"github.com/fatedier/golib/pool"
 
 	v1 "github.com/fatedier/frp/pkg/config/v1"
 	"github.com/fatedier/frp/pkg/transport"
+	"github.com/fatedier/frp/pkg/util/log"
 	netpkg "github.com/fatedier/frp/pkg/util/net"
 )
 
@@ -69,10 +74,13 @@ func NewHTTPS2HTTPSPlugin(options v1.ClientPluginOptions) (Plugin, error) {
 			}
 		},
 		Transport:  tr,
+		BufferPool: pool.NewBuffer(32 * 1024),
+		ErrorLog:   stdlog.New(log.NewWriteLogger(log.WarnLevel, 2), "", 0),
 	}
 
 	p.s = &http.Server{
 		Handler:           rp,
+		ReadHeaderTimeout: 60 * time.Second,
 	}
 
 	var (

pkg/plugin/client/static_file.go

@@ -61,6 +61,7 @@ func NewStaticFilePlugin(options v1.ClientPluginOptions) (Plugin, error) {
 	router.PathPrefix(prefix).Handler(netpkg.MakeHTTPGzipHandler(http.StripPrefix(prefix, http.FileServer(http.Dir(opts.LocalPath))))).Methods("GET")
 	sp.s = &http.Server{
 		Handler:           router,
+		ReadHeaderTimeout: 60 * time.Second,
 	}
 	go func() {
 		_ = sp.s.Serve(listener)

pkg/util/log/log.go

@@ -15,11 +15,20 @@
 package log
 
 import (
+	"bytes"
 	"os"
 
 	"github.com/fatedier/golib/log"
 )
 
+var (
+	TraceLevel = log.TraceLevel
+	DebugLevel = log.DebugLevel
+	InfoLevel  = log.InfoLevel
+	WarnLevel  = log.WarnLevel
+	ErrorLevel = log.ErrorLevel
+)
+
 var Logger *log.Logger
 
 func init() {
@@ -77,3 +86,24 @@ func Debugf(format string, v ...interface{}) {
 func Tracef(format string, v ...interface{}) {
 	Logger.Tracef(format, v...)
 }
+
+func Logf(level log.Level, offset int, format string, v ...interface{}) {
+	Logger.Logf(level, offset, format, v...)
+}
+
+type WriteLogger struct {
+	level  log.Level
+	offset int
+}
+
+func NewWriteLogger(level log.Level, offset int) *WriteLogger {
+	return &WriteLogger{
+		level:  level,
+		offset: offset,
+	}
+}
+
+func (w *WriteLogger) Write(p []byte) (n int, err error) {
+	Logger.Log(w.level, w.offset, string(bytes.TrimRight(p, "\n")))
+	return len(p), nil
+}

pkg/util/net/dial.go

@@ -5,11 +5,11 @@ import (
 	"net"
 	"net/url"
 
-	libdial "github.com/fatedier/golib/net/dial"
+	libnet "github.com/fatedier/golib/net"
 	"golang.org/x/net/websocket"
 )
 
-func DialHookCustomTLSHeadByte(enableTLS bool, disableCustomTLSHeadByte bool) libdial.AfterHookFunc {
+func DialHookCustomTLSHeadByte(enableTLS bool, disableCustomTLSHeadByte bool) libnet.AfterHookFunc {
 	return func(ctx context.Context, c net.Conn, addr string) (context.Context, net.Conn, error) {
 		if enableTLS && !disableCustomTLSHeadByte {
 			_, err := c.Write([]byte{byte(FRPTLSHeadByte)})
@@ -21,7 +21,7 @@ func DialHookCustomTLSHeadByte(enableTLS bool, disableCustomTLSHeadByte bool) li
 	}
 }
 
-func DialHookWebsocket(protocol string, host string) libdial.AfterHookFunc {
+func DialHookWebsocket(protocol string, host string) libnet.AfterHookFunc {
 	return func(ctx context.Context, c net.Conn, addr string) (context.Context, net.Conn, error) {
 		if protocol != "wss" {
 			protocol = "ws"

pkg/util/net/websocket.go

@@ -4,6 +4,7 @@ import (
 	"errors"
 	"net"
 	"net/http"
+	"time"
 
 	"golang.org/x/net/websocket"
 )
@@ -41,6 +42,7 @@ func NewWebsocketListener(ln net.Listener) (wl *WebsocketListener) {
 	wl.server = &http.Server{
 		Addr:              ln.Addr().String(),
 		Handler:           muxer,
+		ReadHeaderTimeout: 60 * time.Second,
 	}
 
 	go func() {

pkg/util/vhost/http.go

@@ -15,7 +15,6 @@
 package vhost
 
 import (
-	"bytes"
 	"context"
 	"encoding/base64"
 	"errors"
@@ -116,10 +115,16 @@ func NewHTTPReverseProxy(option HTTPReverseProxyOptions, vhostRouter *Routers) *
 				return nil, nil
 			},
 		},
-		BufferPool: newWrapPool(),
-		ErrorLog:   stdlog.New(newWrapLogger(), "", 0),
+		BufferPool: pool.NewBuffer(32 * 1024),
+		ErrorLog:   stdlog.New(log.NewWriteLogger(log.WarnLevel, 2), "", 0),
 		ErrorHandler: func(rw http.ResponseWriter, req *http.Request, err error) {
-			log.Warnf("do http proxy request [host: %s] error: %v", req.Host, err)
+			log.Logf(log.WarnLevel, 1, "do http proxy request [host: %s] error: %v", req.Host, err)
+			if err != nil {
+				if e, ok := err.(net.Error); ok && e.Timeout() {
+					rw.WriteHeader(http.StatusGatewayTimeout)
+					return
+				}
+			}
 			rw.WriteHeader(http.StatusNotFound)
 			_, _ = rw.Write(getNotFoundPageContent())
 		},
@@ -322,20 +327,3 @@ func (rp *HTTPReverseProxy) ServeHTTP(rw http.ResponseWriter, req *http.Request)
 		rp.proxy.ServeHTTP(rw, newreq)
 	}
 }
-
-type wrapPool struct{}
-
-func newWrapPool() *wrapPool { return &wrapPool{} }
-
-func (p *wrapPool) Get() []byte { return pool.GetBuf(32 * 1024) }
-
-func (p *wrapPool) Put(buf []byte) { pool.PutBuf(buf) }
-
-type wrapLogger struct{}
-
-func newWrapLogger() *wrapLogger { return &wrapLogger{} }
-
-func (l *wrapLogger) Write(p []byte) (n int, err error) {
-	log.Warnf("%s", string(bytes.TrimRight(p, "\n")))
-	return len(p), nil
-}

pkg/util/vhost/https_test.go

@@ -12,7 +12,7 @@ import (
 func TestGetHTTPSHostname(t *testing.T) {
 	require := require.New(t)
 
-	l, err := net.Listen("tcp", ":")
+	l, err := net.Listen("tcp", "127.0.0.1:")
 	require.NoError(err)
 	defer l.Close()
 

server/service.go

@@ -288,10 +288,11 @@ func NewService(cfg *v1.ServerConfig) (*Service, error) {
 		server := &http.Server{
 			Addr:              address,
 			Handler:           rp,
+			ReadHeaderTimeout: 60 * time.Second,
 		}
 		var l net.Listener
 		if httpMuxOn {
-			l = svr.muxer.ListenHttp(1)
+			l = svr.muxer.ListenHTTP(1)
 		} else {
 			l, err = net.Listen("tcp", address)
 			if err != nil {
@@ -308,7 +309,7 @@ func NewService(cfg *v1.ServerConfig) (*Service, error) {
 	if cfg.VhostHTTPSPort > 0 {
 		var l net.Listener
 		if httpsMuxOn {
-			l = svr.muxer.ListenHttps(1)
+			l = svr.muxer.ListenHTTPS(1)
 		} else {
 			address := net.JoinHostPort(cfg.ProxyBindAddr, strconv.Itoa(cfg.VhostHTTPSPort))
 			l, err = net.Listen("tcp", address)

test/e2e/framework/framework.go

@@ -260,7 +260,7 @@ func (f *Framework) SetEnvs(envs []string) {
 
 func (f *Framework) WriteTempFile(name string, content string) string {
 	filePath := filepath.Join(f.TempDirectory, name)
-	err := os.WriteFile(filePath, []byte(content), 0o766)
+	err := os.WriteFile(filePath, []byte(content), 0o600)
 	ExpectNoError(err)
 	return filePath
 }

test/e2e/framework/process.go

@@ -27,7 +27,7 @@ func (f *Framework) RunProcesses(serverTemplates []string, clientTemplates []str
 	currentServerProcesses := make([]*process.Process, 0, len(serverTemplates))
 	for i := range serverTemplates {
 		path := filepath.Join(f.TempDirectory, fmt.Sprintf("frp-e2e-server-%d", i))
-		err = os.WriteFile(path, []byte(outs[i]), 0o666)
+		err = os.WriteFile(path, []byte(outs[i]), 0o600)
 		ExpectNoError(err)
 
 		if TestContext.Debug {
@@ -48,7 +48,7 @@ func (f *Framework) RunProcesses(serverTemplates []string, clientTemplates []str
 	for i := range clientTemplates {
 		index := i + len(serverTemplates)
 		path := filepath.Join(f.TempDirectory, fmt.Sprintf("frp-e2e-client-%d", i))
-		err = os.WriteFile(path, []byte(outs[index]), 0o666)
+		err = os.WriteFile(path, []byte(outs[index]), 0o600)
 		ExpectNoError(err)
 
 		if TestContext.Debug {
@@ -94,7 +94,7 @@ func (f *Framework) RunFrpc(args ...string) (*process.Process, string, error) {
 func (f *Framework) GenerateConfigFile(content string) string {
 	f.configFileIndex++
 	path := filepath.Join(f.TempDirectory, fmt.Sprintf("frp-e2e-config-%d", f.configFileIndex))
-	err := os.WriteFile(path, []byte(content), 0o666)
+	err := os.WriteFile(path, []byte(content), 0o600)
 	ExpectNoError(err)
 	return path
 }

test/e2e/pkg/request/request.go

@@ -12,7 +12,7 @@ import (
 	"strconv"
 	"time"
 
-	libdial "github.com/fatedier/golib/net/dial"
+	libnet "github.com/fatedier/golib/net"
 
 	httppkg "github.com/fatedier/frp/pkg/util/http"
 	"github.com/fatedier/frp/test/e2e/pkg/rpc"
@@ -160,11 +160,11 @@ func (r *Request) Do() (*Response, error) {
 		if r.protocol != "tcp" {
 			return nil, fmt.Errorf("only tcp protocol is allowed for proxy")
 		}
-		proxyType, proxyAddress, auth, err := libdial.ParseProxyURL(r.proxyURL)
+		proxyType, proxyAddress, auth, err := libnet.ParseProxyURL(r.proxyURL)
 		if err != nil {
 			return nil, fmt.Errorf("parse ProxyURL error: %v", err)
 		}
-		conn, err = libdial.Dial(addr, libdial.WithProxy(proxyType, proxyAddress), libdial.WithProxyAuth(auth))
+		conn, err = libnet.Dial(addr, libnet.WithProxy(proxyType, proxyAddress), libnet.WithProxyAuth(auth))
 		if err != nil {
 			return nil, err
 		}

test/e2e/v1/basic/http.go

@@ -5,6 +5,7 @@ import (
 	"net/http"
 	"net/url"
 	"strconv"
+	"time"
 
 	"github.com/gorilla/websocket"
 	"github.com/onsi/ginkgo/v2"
@@ -385,4 +386,48 @@ var _ = ginkgo.Describe("[Feature: HTTP]", func() {
 		framework.ExpectNoError(err)
 		framework.ExpectEqualValues(consts.TestString, string(msg))
 	})
+
+	ginkgo.It("vhostHTTPTimeout", func() {
+		vhostHTTPPort := f.AllocPort()
+		serverConf := getDefaultServerConf(vhostHTTPPort)
+		serverConf += `
+		vhostHTTPTimeout = 2
+		`
+
+		delayDuration := 0 * time.Second
+		localPort := f.AllocPort()
+		localServer := httpserver.New(
+			httpserver.WithBindPort(localPort),
+			httpserver.WithHandler(http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
+				time.Sleep(delayDuration)
+				_, _ = w.Write([]byte(req.Host))
+			})),
+		)
+		f.RunServer("", localServer)
+
+		clientConf := consts.DefaultClientConfig
+		clientConf += fmt.Sprintf(`
+			[[proxies]]
+			name = "test"
+			type = "http"
+			localPort = %d
+			customDomains = ["normal.example.com"]
+			`, localPort)
+
+		f.RunProcesses([]string{serverConf}, []string{clientConf})
+
+		framework.NewRequestExpect(f).Port(vhostHTTPPort).
+			RequestModify(func(r *request.Request) {
+				r.HTTP().HTTPHost("normal.example.com").HTTP().Timeout(time.Second)
+			}).
+			ExpectResp([]byte("normal.example.com")).
+			Ensure()
+
+		delayDuration = 3 * time.Second
+		framework.NewRequestExpect(f).Port(vhostHTTPPort).
+			RequestModify(func(r *request.Request) {
+				r.HTTP().HTTPHost("normal.example.com").HTTP().Timeout(5 * time.Second)
+			}).
+			Ensure(framework.ExpectResponseCode(504))
+	})
 })