tusd icon indicating copy to clipboard operation
tusd copied to clipboard

Multiple data race issues

Open wongak opened this issue 1 year ago • 5 comments

Describe the bug tusd.Config{} Logger is set. When performing an upload a data race is reported:

==================
WARNING: DATA RACE
Write at 0x00c0006ae3b0 by goroutine 349:
  github.com/tus/tusd/v2/pkg/handler.(*UnroutedHandler).PostFile()
      .../vendor/github.com/tus/tusd/v2/pkg/handler/unrouted_handler.go:398 +0xb60
...
Previous read at 0x00c0006ae3b0 by goroutine 398:
  github.com/tus/tusd/v2/pkg/handler.(*httpContext).Value()
      <autogenerated>:1 +0x44

To Reproduce Steps to reproduce the behavior:

  1. Configure a logger
  2. Run with -race

Currently still investigating which other circumstances lead to this.

But

	c.log = c.log.With("id", id)

writing to a context without creating a copy is probably not correct.

Expected behavior No data race should happen

Setup details Please provide following details, if applicable to your situation:

  • Operating System: macOS
  • Used tusd version: github.com/tus/tusd/v2 v2.4.0
  • Used tusd data storage: S3 with local minio

wongak avatar Sep 22 '24 12:09 wongak

Unfortunately this uncovers quite a few more data race issues, which go beyond the scope of this issue:

==================
WARNING: DATA RACE
Write at 0x00c0000c40a0 by goroutine 205:
  github.com/tus/tusd/v2/pkg/handler.(*bodyReader).closeWithError()
      .../tusd/pkg/handler/body_reader.go:123 +0x3c
  github.com/tus/tusd/v2/pkg/handler.UnroutedHandler.newContext.func1()
      .../tusd/pkg/handler/context.go:66 +0x13c

Previous read at 0x00c0000c40a0 by goroutine 202:
  github.com/tus/tusd/v2/pkg/handler.(*bodyReader).Read()
      .../tusd/pkg/handler/body_reader.go:44 +0x40
  io.ReadAll()
      .../go/1.23.1/libexec/src/io/io.go:712 +0x84

and

==================
WARNING: DATA RACE
Write at 0x00c0002180e0 by goroutine 130:
  github.com/tus/tusd/v2/pkg/s3store.(*s3Upload).uploadParts.func2()
      .../tusd/pkg/s3store/s3store.go:515 +0x4dc
  github.com/tus/tusd/v2/pkg/s3store.(*s3Upload).uploadParts.gowrap2()
      .../tusd/pkg/s3store/s3store.go:522 +0x6c

Previous write at 0x00c0002180e0 by goroutine 131:
  github.com/tus/tusd/v2/pkg/s3store.(*s3Upload).uploadParts.func2()
      .../tusd/pkg/s3store/s3store.go:515 +0x4dc
  github.com/tus/tusd/v2/pkg/s3store.(*s3Upload).uploadParts.gowrap2()
      .../tusd/pkg/s3store/s3store.go:522 +0x6c

wongak avatar Sep 22 '24 13:09 wongak

Updated the issue. This requires a rework of the context implementation.

wongak avatar Sep 30 '24 06:09 wongak

Thank you for bringing this up! I haven't used the data race detector before, so tusd hasn't been vetted by it so far, but we should change this.

Running the race detector during tests also shows a few issues (go test -race ./pkg/handler/). Most of these should likely be easy to address through the use of sync/atomic. For the logger, we can move the call to .With("id", id) when constructing the context in the first place.

I'll have a look at them soon.

Acconut avatar Oct 04 '24 09:10 Acconut

Opened https://github.com/tus/tusd/pull/1199.

Acconut avatar Oct 04 '24 09:10 Acconut

I addressed the data races in handler and s3store in https://github.com/tus/tusd/pull/1199, but not the logger-related one yet.

Acconut avatar Oct 04 '24 12:10 Acconut

We don't seem to be able to reproduce this specific data race anymore (see https://github.com/tus/tusd/pull/1193#issuecomment-2471067803). Since the other races have been fixed, I will close this issue for now. Feel free to reopen it if the problem appears again.

Acconut avatar Nov 12 '24 16:11 Acconut