upgrade to v5: curl sometimes reports: curl: (92) HTTP/2 stream 1 was not closed cleanly: INTERNAL_ERROR (err 2) #2918

Activity

1. aldas commented on Mar 19, 2026

   

   aldas

   on Mar 19, 2026

   Contributor

   More actions

   if you add recovery middleware - does it change?

   	e.Use(middleware.RequestLogger())
   	e.Use(middleware.Recover())
2. comphilip commented on Mar 19, 2026

   

   comphilip

   on Mar 19, 2026

   Last edited by comphilip

   Author

   More actions

   with middleware.RequestLogger() but no middleware.Recover(), got error log

   time=2026-03-19T09:01:06.549Z level=ERROR msg=REQUEST_ERROR method=GET uri=/v1/streams/2630/log/20260319 status=200 latency=30.001921489s host=internal.unitloop.com bytes_in="" bytes_out=917704696 user_agent=curl/8.5.0 remote_ip=10.249.20.7 request_id="" error="write tcp 10.42.0.222:80->10.42.2.0:44176: i/o timeout"
   
3. aldas commented on Mar 19, 2026

   

   aldas

   on Mar 19, 2026

   Contributor

   More actions

   but write tcp 10.42.0.222:80->10.42.2.0:44176: i/o timeout seems more like the Go HTTP server that Echo uses can not send the response to the connected client.
   And you say that at the other end (Client side) you see incorrectly closed connections.
   This seems to indicate that some proxy between the client and HTTP server is closing the connection or there are network problems temporarly.
4. comphilip commented on Mar 19, 2026

   

   comphilip

   on Mar 19, 2026

   Author

   More actions

   10.42.0.222:80->10.42.2.0:44176, 10.42.0.222:80 is echo service k8s pod address, 10.42.2.0:44176 is traefik proxy pod address

   client <---> traefik proxy <---> echo service, all of them in same local network (same data rack), network speed is 10G, wonder why write tcp timeout
5. aldas commented on Mar 19, 2026

   

   aldas

   on Mar 19, 2026

   Last edited by aldas

   Contributor

   More actions

   maybe there are some reconfigurations done in k8 network or traefik proxy is being redeployed/reloaded? Or another theory - it could happen when the client has bad connection - something like poor wifi connection.

   edit: I forgot that everything is in the same rack.
6. aldas commented on Mar 19, 2026

   

   aldas

   on Mar 19, 2026

   Contributor

   More actions

   are you using only CORS, RequestLogger, Prometheus middlewares? If you look inside debugger at c.Response() - how many http.ResponseWriter it is wrapping?
7. comphilip commented on Mar 19, 2026

   

   comphilip

   on Mar 19, 2026

   Author

   More actions

   for a simple static file service, only

   		e.Use(middleware.CORS("*"))
   		e.Use(middleware.RequestLogger())
   		e.Use(echoprometheus.NewMiddleware("echo"))
   

   echo v5 on 2026-03-17 on business idle time window, no other system component changed: traefik, kubernetes and so on.

   then issues happened since 2026-03-18
8. aldas commented on Mar 19, 2026

   

   aldas

   on Mar 19, 2026

   Last edited by aldas

   Contributor

   More actions

   Well. v4 has hack for listener KeepAlive. This should not be the for a long time, as Go standard library did some changes related to that in ~1.10 but to be use you can try to deploy custom http server that creates these same listener as v4 does.

   package main
   
   import (
   	"context"
   	"errors"
   	"log/slog"
   	"net"
   	"net/http"
   	"os"
   	"os/signal"
   	"syscall"
   	"time"
   
   	"github.com/labstack/echo/v5"
   	"github.com/labstack/echo/v5/middleware"
   )
   
   func main() {
   	e := echo.New()
   	e.Logger = slog.New(slog.NewTextHandler(os.Stdout, nil))
   
   	e.Use(middleware.CORS("*"))
   	e.Use(middleware.RequestLogger())
   	e.Use(middleware.Recover())
   	//e.Use(echoprometheus.NewMiddleware("echo"))
   
   	//e.Static("/package/", argv.PackageDirectory)
   
   	//port := fmt.Sprintf(":%d", argv.ListenPort)
   	port := ":8080"
   	runServer(e, port)
   }
   
   func runServer(e *echo.Echo, port string) {
   	listner, err := newListener(port, "tcp")
   	if err != nil {
   		slog.Error("failed to create listener", "error", err)
   		return
   	}
   	defer listner.Close()
   
   	s := http.Server{
   		Handler:           e,
   		ReadHeaderTimeout: 30 * time.Second,
   		WriteTimeout:      30 * time.Second,
   	}
   
   	serverErr := make(chan error, 1)
   	go func() {
   		if err := s.Serve(listner); err != nil && !errors.Is(err, http.ErrServerClosed) {
   			serverErr <- nil
   			return
   		}
   		serverErr <- nil
   	}()
   
   	ctx, cancel := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM)
   	defer cancel()
   	select {
   	case err := <-serverErr:
   		if err != nil {
   			e.Logger.Error("failed to run server", "error", err)
   		}
   		return
   	case <-ctx.Done():
   	}
   
   	if err := s.Shutdown(ctx); err != nil {
   		e.Logger.Error("failed to shutdown server", "error", err)
   		if err := s.Close(); err != nil {
   			e.Logger.Error("failed to close server", "error", err)
   		}
   	}
   }
   
   // tcpKeepAliveListener sets TCP keep-alive timeouts on accepted
   // connections. It's used by ListenAndServe and ListenAndServeTLS so
   // dead TCP connections (e.g. closing laptop mid-download) eventually
   // go away.
   type tcpKeepAliveListener struct {
   	*net.TCPListener
   }
   
   func (ln tcpKeepAliveListener) Accept() (c net.Conn, err error) {
   	if c, err = ln.AcceptTCP(); err != nil {
   		return
   	} else if err = c.(*net.TCPConn).SetKeepAlive(true); err != nil {
   		return
   	}
   	// Ignore error from setting the KeepAlivePeriod as some systems, such as
   	// OpenBSD, do not support setting TCP_USER_TIMEOUT on IPPROTO_TCP
   	_ = c.(*net.TCPConn).SetKeepAlivePeriod(3 * time.Minute)
   	return
   }
   
   func newListener(address, network string) (*tcpKeepAliveListener, error) {
   	l, err := net.Listen(network, address)
   	if err != nil {
   		return nil, err
   	}
   	return &tcpKeepAliveListener{l.(*net.TCPListener)}, nil
   }
9. aldas commented on Mar 19, 2026

   

   aldas

   on Mar 19, 2026

   Contributor

   More actions

   note to self: echo.StartConfig should have way to use custom Listeners.
   relates to #1942
10. comphilip commented on Mar 19, 2026

    

    comphilip

    on Mar 19, 2026

    Author

    More actions

    I can reproduce the error in localhost, just echo web server and curl directly.

    1. static host a directory contains a big file, in localhost
    2. download at 1MBps via curl --limit-rate 1M -o /dev/null http://localhost:8000/package/big.log
    3. echo closes connection about 40 seconds

    environment: Ubuntu 24.04.3 LTS"

    func main() {
    	os.Exit(cli.Run(new(options), func(ctx *cli.Context) error {
    		argv := ctx.Argv().(*options)
    
    		e := echo.New()
    		e.Logger = slog.New(slog.NewTextHandler(os.Stdout, nil))
    		e.Use(middleware.RequestLogger())
    		e.Static("/", argv.PackageDirectory)
    		log.Fatal(e.Start(fmt.Sprintf(":%d", argv.ListenPort)))
    		return nil
    	}))
    }

    echo log

    time=2026-03-19T21:57:43.423+08:00 level=INFO msg="Echo (v5.0.4). High performance, minimalist Go web framework https://echo.labstack.com" version=5.0.4
    time=2026-03-19T21:57:43.423+08:00 level=INFO msg="http(s) server started" address=[::]:8000
    time=2026-03-19T21:58:42.898+08:00 level=INFO msg=REQUEST method=GET uri=/big.log status=200 latency=30.000434905s host=localhost:8000 bytes_in="" bytes_out=41771288 user_agent=curl/8.5.0 remote_ip=::1 request_id=""
    

    curl

    curl --limit-rate 1M  -o /dev/null http://localhost:8000/big.log
      % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                     Dload  Upload   Total   Spent    Left  Speed
      4  992M    4 39.8M    0     0  1024k      0  0:16:31  0:00:39  0:15:52 1007k
    curl: (18) transfer closed with 998498709 bytes remaining to read
11. comphilip commented on Mar 19, 2026

    

    comphilip

    on Mar 19, 2026

    Author

    More actions

    with github copilt's help, I need to override WriteTimeout to zero

    		sc := echo.StartConfig{
    			Address: fmt.Sprintf(":%d", argv.ListenPort),
    			BeforeServeFunc: func(s *http.Server) error {
    				s.WriteTimeout = 0
    				return nil
    			},
    		}
    		if err := sc.Start(context.Background(), e); !errors.Is(err, http.ErrServerClosed) {
    			log.Panic(err)
    		}

    Thanks #2883 , Also #1953 , there is no error log even though the connection is closed by timeout, hard to troubleshooting
12. comphilip

    closed this as completedon Mar 19, 2026
13. aldas commented on Mar 20, 2026

    

    aldas

    on Mar 20, 2026

    Contributor

    More actions

    @comphilip if this problems reappears or did not go away, let me know. I am not convinced that WriteTimeout=0 is here the reason why v4 worked and v5 not.

    Docs say

    	// WriteTimeout is the maximum duration before timing out
    	// writes of the response. It is reset whenever a new
    	// request's header is read. Like ReadTimeout, it does not
    	// let Handlers make decisions on a per-request basis.
    	// A zero or negative value means there will be no timeout.
    

    It could help maybe with streaming then there are no messages to the client for some time.
14. comphilip commented on Mar 20, 2026

    

    comphilip

    on Mar 20, 2026

    Author

    More actions

    @aldas problems gone away after WriteTimeout=0
15. aldas commented on Mar 20, 2026

    

    aldas

    on Mar 20, 2026

    Contributor

    More actions

    ok, but I think the keepalive is probably the issue here then. WriteTimeout is not changed from v4 to v5 but keepalive part was.
16. comphilip commented on Mar 20, 2026

    

    comphilip

    on Mar 20, 2026

    Last edited by comphilip

    Author

    More actions

    @aldas I doubt that it maybe not keepalive issue for my small reproduce issue sample code: #2918 (comment)
17. aldas commented on Mar 31, 2026

    

    aldas

    on Mar 31, 2026

    Contributor

    More actions

    @comphilip we had similar issue related to SSE and I have decided that Start methods should not set http.Server.WriteTimeout = 30 time.Second any more. This will be released soon.

    I do not know what brain fart I had but I did not connect that we did not set that field in v4 and v5 we do.

    ❤️React with ❤️1Reacted by Philip Chan