Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[query] Avoid errors when closing shared listener #5559

Merged
merged 9 commits into from
Jun 12, 2024
Merged

[query] Avoid errors when closing shared listener #5559

Changes from 6 commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
65f6cba
Fix flaky TestServerSinglePort by adding dynamic port assignment and …
vermaaatul07 Jun 11, 2024
bc68cba
Refine logging and error handling in server operations
vermaaatul07 Jun 11, 2024
d5fb088
Improve error handling and logging in server start and close methods
vermaaatul07 Jun 12, 2024
f8e7c45
Add detailed logging and error handling as per maintainer's feedback
vermaaatul07 Jun 12, 2024
75351a8
Implement enhanced logging and error handling for TestServerSinglePort
vermaaatul07 Jun 12, 2024
3d35a4b
Improve error handling and add logging for Close method
vermaaatul07 Jun 12, 2024
150a04c
Merge branch 'main' into fix-flaky-test
yurishkuro Jun 12, 2024
bafa622
clean-up
yurishkuro Jun 12, 2024
8be6e17
clean-up
yurishkuro Jun 12, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
36 changes: 31 additions & 5 deletions cmd/query/app/server.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -274,7 +274,7 @@ func (s *Server) initListener() (cmux.CMux, error) {
func (s *Server) Start() error {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

you should add this option to the logger in the test:

	flagsSvc.Logger = zaptest.NewLogger(t, zaptest.WrapOptions(zap.AddCaller()))

that way it prints the source line.

I changed the timeout to 2s and look what the logs say:

    logger.go:146: 2024-06-12T15:13:20.232-0400 INFO    app/static_handler.go:109       Using UI configuration  {"path": ""}
    logger.go:146: 2024-06-12T15:13:20.234-0400 INFO    app/server.go:256       Query server started    {"port": 16686, "addr": ":16686"}
    logger.go:146: 2024-06-12T15:13:20.234-0400 INFO    app/server.go:300       Starting HTTP server    {"port": 16686, "addr": ":16686"}
    logger.go:146: 2024-06-12T15:13:20.234-0400 INFO    app/server.go:332       Starting CMUX server    {"port": 16686, "addr": ":16686"}
    logger.go:146: 2024-06-12T15:13:20.234-0400 INFO    app/server.go:318       Starting GRPC server    {"port": 16686, "addr": ":16686"}
    logger.go:146: 2024-06-12T15:13:20.283-0400 INFO    app/server.go:358       Stopping gRPC server
    logger.go:146: 2024-06-12T15:13:20.284-0400 INFO    app/server.go:310       HTTP server stopped     {"port": 16686, "addr": ":16686"}
    logger.go:146: 2024-06-12T15:13:20.284-0400 INFO    app/server.go:323       GRPC server stopped     {"port": 16686, "addr": ":16686"}
    logger.go:146: 2024-06-12T15:13:22.285-0400 INFO    app/server.go:362       Closing HTTP server
    logger.go:146: 2024-06-12T15:13:24.286-0400 INFO    app/server.go:369       Closing CMux server
    logger.go:146: 2024-06-12T15:13:24.286-0400 INFO    app/server.go:375       Server stopped

note that after Stopping gRPC server we're seeing HTTP server stopped, even before Closing HTTP server. When I add a log line for CMUX server goroutine, it also logs that CMUX server is stopped before we come to trying to stop HTTP. So it seems when we're running on a single port it's simply sufficient to close gRPC server, which closes the underlying listenter, and all other servers exit automatically (we do already catch ErrServerClosed errors and don't log them).

cmuxServer, err := s.initListener()
if err != nil {
return err
return fmt.Errorf("query server failed to initialize listener: %w", err)
}
s.cmuxServer = cmuxServer

Expand Down Expand Up @@ -344,16 +344,42 @@ func (s *Server) Start() error {
return nil
}

// Close stops http, GRPC servers and closes the port listener.
// Close stops HTTP, GRPC servers and closes the port listener.
func (s *Server) Close() error {
var errs []error
errs = append(errs, s.queryOptions.TLSGRPC.Close())
errs = append(errs, s.queryOptions.TLSHTTP.Close())

if err := s.queryOptions.TLSGRPC.Close(); err != nil && !isConnAlreadyClosedError(err) {
errs = append(errs, fmt.Errorf("failed to close TLS gRPC server: %w", err))
}
time.Sleep(200 * time.Millisecond)

if err := s.queryOptions.TLSHTTP.Close(); err != nil && !isConnAlreadyClosedError(err) {
errs = append(errs, fmt.Errorf("failed to close TLS HTTP server: %w", err))
}
time.Sleep(200 * time.Millisecond)
yurishkuro marked this conversation as resolved.
Show resolved Hide resolved

s.logger.Info("Stopping gRPC server")
s.grpcServer.Stop()
errs = append(errs, s.httpServer.Close())
time.Sleep(200 * time.Millisecond)

s.logger.Info("Closing HTTP server")
if err := s.httpServer.Close(); err != nil && !isConnAlreadyClosedError(err) {
errs = append(errs, fmt.Errorf("failed to close HTTP server: %w", err))
}
time.Sleep(200 * time.Millisecond)

if !s.separatePorts {
s.logger.Info("Closing CMux server")
s.cmuxServer.Close()
}

s.bgFinished.Wait()

s.logger.Info("Server stopped")
return errors.Join(errs...)
}

// Helper function to check if an error is "conn already closed"
func isConnAlreadyClosedError(err error) bool {
return strings.Contains(err.Error(), "use of closed network connection")
}