🐛 [Bug]: Data race on shutdown

[cherryReptile]

Bug Description

I have a data race, when I call *fiber.App.Shutdown() methods and have some unprocessed requests , which handlers uses a request ctx

Snippet of data race message:

Previous read at 0x00c00023d1f8 by goroutine 45:
  github.com/valyala/fasthttp.(*RequestCtx).Done()
      ~/go/pkg/mod/github.com/valyala/[email protected]/server.go:2726 +0x6a
  context.(*cancelCtx).propagateCancel.func2()
      /usr/local/go/src/context/context.go:511 +0x62

How to Reproduce

1. Handler that uses request ctx for needed funcs
2. Run app with -race flag
3. Do some requests to server and start shutdown
4. See data race by *fiber.RequestCtx

Expected Behavior

I think this data race was not in plan

Fiber Version

2.52.4

Code Snippet (optional)

func (h *Handler) CreateTopic(c *fiber.Ctx) error {
	topic := new(feedback.Topic)

	if err := c.BodyParser(topic); err != nil {
		return err
	}

	id, err := h.feedbackService.CreateTopic(c.Context(), topic)
	if err != nil {
		return err
	}

	return c.Status(fiber.StatusCreated).JSON(map[string]string{"id": id})
}

Checklist:

• [X] I agree to follow Fiber's Code of Conduct.
• [X] I have checked for existing issues that describe my problem prior to opening this one.
• [X] I understand that improperly formatted bug reports may be closed without explanation.

[welcome[bot]]

Thanks for opening your first issue here! 🎉 Be sure to follow the issue template! If you need help or want to chat with us, join us on Discord https://gofiber.io/discord

[H0llyW00dzZ]

Bug Description

I have a data race, when I call *fiber.App.Shutdown() methods and have some unprocessed requests , which handlers uses a request ctx

Snippet of data race message:

Previous read at 0x00c00023d1f8 by goroutine 45:
  github.com/valyala/fasthttp.(*RequestCtx).Done()
      ~/go/pkg/mod/github.com/valyala/[email protected]/server.go:2726 +0x6a
  context.(*cancelCtx).propagateCancel.func2()
      /usr/local/go/src/context/context.go:511 +0x62

How to Reproduce

1. Handler that uses request ctx for needed funcs
2. Run app with -race flag
3. Do some requests to server and start shutdown
4. See data race by *fiber.RequestCtx

Expected Behavior

I think this data race was not in plan

Fiber Version

2.52.4

Code Snippet (optional)

func (h *Handler) CreateTopic(c *fiber.Ctx) error {
	topic := new(feedback.Topic)

	if err := c.BodyParser(topic); err != nil {
		return err
	}

	id, err := h.feedbackService.CreateTopic(c.Context(), topic)
	if err != nil {
		return err
	}

	return c.Status(fiber.StatusCreated).JSON(map[string]string{"id": id})
}

Checklist:

• [x] I agree to follow Fiber's Code of Conduct.
• [x] I have checked for existing issues that describe my problem prior to opening this one.
• [x] I understand that improperly formatted bug reports may be closed without explanation.

You have to use this method, I think, because it works fine for me, and I'm using Go 1.22.1

example:

// waitForShutdownSignal blocks execution until an OS interrupt or SIGTERM signal is received,
// then it gracefully shuts down the Fiber app within the specified timeout.
func waitForShutdownSignal(shutdownTimeout time.Duration, app *fiber.App, db database.Service) {
	// Setting up signal capturing.
	quit := make(chan os.Signal, 1)
	signal.Notify(quit, os.Interrupt, syscall.SIGTERM)

	// Blocking until a signal is received.
	sig := <-quit
	Logger.LogInfof("Shutting down server... reason: %v", sig)

	// Start graceful shutdown in a separate goroutine.
	go func() {
		// Shutdown the Fiber app
		if err := app.Shutdown(); err != nil {
			Logger.LogErrorf("Server forced to shutdown: %v", err)
		}

		// Clean up resources and close the database connection
		cleanup(db)
	}()

	// Create a timer that will wait for the shutdownTimeout to elapse
	shutdownTimer := time.NewTimer(shutdownTimeout)
	defer shutdownTimer.Stop()

	// Wait for the timeout to elapse
	<-shutdownTimer.C
	Logger.LogInfo("Server exiting")
}

logs:

$ go run cmd/api/main.go
2024/03/31 14:44:15 [H0llyW00dzZ] [INFO] Starting server on :8080

 ┌───────────────────────────────────────────────────┐
 │                    H0llyW00dzZ                    │
 │                   Fiber v2.52.4                   │
 │               http://127.0.0.1:8080               │
 │       (bound on host 0.0.0.0 and port 8080)       │
 │                                                   │
 │ Handlers ............ 534 Processes ........... 1 │
 │ Prefork ....... Disabled  PID .............. 6860 │
 └───────────────────────────────────────────────────┘

2024/03/31 14:44:22 [H0llyW00dzZ] [INFO] Shutting down server... reason: interrupt
2024/03/31 14:44:23 [H0llyW00dzZ] [INFO] Disconnected from database: defaultdb
2024/03/31 14:44:23 [H0llyW00dzZ] [INFO] Database connection closed.
2024/03/31 14:44:27 [H0llyW00dzZ] [INFO] Server exiting

[H0llyW00dzZ]

with -race flag:

$ go run cmd/api/main.go -race flag
2024/03/31 15:05:12 [H0llyW00dzZ] [INFO] Starting server on :8080

 ┌───────────────────────────────────────────────────┐
 │                    H0llyW00dzZ                    │
 │                   Fiber v2.52.4                   │
 │               http://127.0.0.1:8080               │
 │       (bound on host 0.0.0.0 and port 8080)       │
 │                                                   │
 │ Handlers ............ 534 Processes ........... 1 │
 │ Prefork ....... Disabled  PID ............. 16576 │
 └───────────────────────────────────────────────────┘

2024/03/31 15:05:22 [H0llyW00dzZ] [INFO] Shutting down server... reason: interrupt
2024/03/31 15:05:22 [H0llyW00dzZ] [INFO] Disconnected from database: defaultdb
2024/03/31 15:05:22 [H0llyW00dzZ] [INFO] Database connection closed.
2024/03/31 15:05:27 [H0llyW00dzZ] [INFO] Server exiting

[gaby]

Doesn't running with -race make your program super slow?

[cherryReptile]

Doesn't running with -race make your program super slow?

It is only for tests

[cherryReptile]

with -race flag:

$ go run cmd/api/main.go -race flag
2024/03/31 15:05:12 [H0llyW00dzZ] [INFO] Starting server on :8080

 ┌───────────────────────────────────────────────────┐
 │                    H0llyW00dzZ                    │
 │                   Fiber v2.52.4                   │
 │               http://127.0.0.1:8080               │
 │       (bound on host 0.0.0.0 and port 8080)       │
 │                                                   │
 │ Handlers ............ 534 Processes ........... 1 │
 │ Prefork ....... Disabled  PID ............. 16576 │
 └───────────────────────────────────────────────────┘

2024/03/31 15:05:22 [H0llyW00dzZ] [INFO] Shutting down server... reason: interrupt
2024/03/31 15:05:22 [H0llyW00dzZ] [INFO] Disconnected from database: defaultdb
2024/03/31 15:05:22 [H0llyW00dzZ] [INFO] Database connection closed.
2024/03/31 15:05:27 [H0llyW00dzZ] [INFO] Server exiting

I send about 10 requests to a method that uses the request context for further steps, and immediately run the Shutdown method on the interrupt signal (ShutdownWithContext has similar behavior). I accidentally noticed this when app running with the -race flag. So I can fix this using context package in handler, but without request ctx as a parent

[JIeJaitt]

hi bro, Have you determined this is a bug?

[cherryReptile]

hi bro, Have you determined this is a bug?

Not entirely sure, but looks like not exactly expected behavior. What do you think? It’s just that in some places you want to use this request context in case it is interrupted, and a similar problem arises every other time - and only when calling Shutdovn (the case is still the same - about 10 requests or more, then instant strart Shutdovn)

[newacorn]

This issue is related to fasthttp and not fiber. We need you to provide more race condition details. In addition to the 'Previous read' information, we also need the 'Write' information. It indeed appears to be a bug that needs to be fixed.

It would be helpful if you could provide a simplified version of your CreateTopic method. We need to determine whether you're still referencing fasthttp's RequestCtx after the handler returns.