search

go-resty / resty

Simple HTTP and REST client library for Go
MIT License
9.98k stars 706 forks source link

Fixed JSON request logging data race. #775

Closed buglloc closed 7 months ago

buglloc commented 7 months ago

noescapeJSONMarshalIndent must either copy the buffer data or don't put it into the sync.Pool (similar to noescapeJSONMarshal). Otherwise, we could have a data race:

$ go test -run TestDebugLogSimultaneously -race
==================
WARNING: DATA RACE
Write at 0x00c00001e8c0 by goroutine 31:
  runtime.slicecopy()
      /usr/lib/go/src/runtime/slice.go:325 +0x0
  bytes.(*Buffer).Write()
      /usr/lib/go/src/bytes/buffer.go:181 +0x118
  github.com/go-resty/resty/v2.jsonMarshal()
      /home/buglloc/work/projects/resty/util.go:164 +0x158
  github.com/go-resty/resty/v2.handleRequestBody()
      /home/buglloc/work/projects/resty/middleware.go:507 +0x2e7
  github.com/go-resty/resty/v2.parseRequestBody()
      /home/buglloc/work/projects/resty/middleware.go:193 +0x290
  github.com/go-resty/resty/v2.(*Client).execute()
      /home/buglloc/work/projects/resty/client.go:1164 +0x5e5
  github.com/go-resty/resty/v2.(*Request).Execute()
      /home/buglloc/work/projects/resty/request.go:936 +0x4f9
  github.com/go-resty/resty/v2.(*Request).Post()
      /home/buglloc/work/projects/resty/request.go:862 +0x6ed
  github.com/go-resty/resty/v2.TestDebugLogSimultaneously.func1()
      /home/buglloc/work/projects/resty/client_test.go:784 +0x6cb
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:1742 +0x44

Previous read at 0x00c00001e8c0 by goroutine 32:
  runtime.slicebytetostring()
      /usr/lib/go/src/runtime/string.go:81 +0x0
  github.com/go-resty/resty/v2.(*Request).fmtBodyString()
      /home/buglloc/work/projects/resty/request.go:1037 +0x916
  github.com/go-resty/resty/v2.requestLogger()
      /home/buglloc/work/projects/resty/middleware.go:324 +0x3b0
  github.com/go-resty/resty/v2.(*Client).execute()
      /home/buglloc/work/projects/resty/client.go:1180 +0x84b
  github.com/go-resty/resty/v2.(*Request).Execute()
      /home/buglloc/work/projects/resty/request.go:936 +0x4f9
  github.com/go-resty/resty/v2.(*Request).Post()
      /home/buglloc/work/projects/resty/request.go:862 +0x6ed
  github.com/go-resty/resty/v2.TestDebugLogSimultaneously.func1()
      /home/buglloc/work/projects/resty/client_test.go:784 +0x6cb
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:1742 +0x44

Goroutine 31 (running) created at:
  testing.(*T).Run()
      /usr/lib/go/src/testing/testing.go:1742 +0x825
  github.com/go-resty/resty/v2.TestDebugLogSimultaneously()
      /home/buglloc/work/projects/resty/client_test.go:779 +0x24d
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:1742 +0x44

Goroutine 32 (running) created at:
  testing.(*T).Run()
      /usr/lib/go/src/testing/testing.go:1742 +0x825
  github.com/go-resty/resty/v2.TestDebugLogSimultaneously()
      /home/buglloc/work/projects/resty/client_test.go:779 +0x24d
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:1742 +0x44
==================
==================
WARNING: DATA RACE
Write at 0x00c000444200 by goroutine 50:
  runtime.slicecopy()
      /usr/lib/go/src/runtime/slice.go:325 +0x0
  bytes.(*Buffer).Write()
      /usr/lib/go/src/bytes/buffer.go:181 +0x118
  encoding/json.(*Encoder).Encode()
      /usr/lib/go/src/encoding/json/stream.go:230 +0x46b
  github.com/go-resty/resty/v2.init.func3()
      /home/buglloc/work/projects/resty/request.go:1088 +0x20a
  github.com/go-resty/resty/v2.(*Request).fmtBodyString()
      /home/buglloc/work/projects/resty/request.go:1017 +0x531
  github.com/go-resty/resty/v2.requestLogger()
      /home/buglloc/work/projects/resty/middleware.go:324 +0x3b0
  github.com/go-resty/resty/v2.(*Client).execute()
      /home/buglloc/work/projects/resty/client.go:1180 +0x84b
  github.com/go-resty/resty/v2.(*Request).Execute()
      /home/buglloc/work/projects/resty/request.go:936 +0x4f9
  github.com/go-resty/resty/v2.(*Request).Post()
      /home/buglloc/work/projects/resty/request.go:862 +0x6ed
  github.com/go-resty/resty/v2.TestDebugLogSimultaneously.func1()
      /home/buglloc/work/projects/resty/client_test.go:784 +0x6cb
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:1742 +0x44

Previous read at 0x00c000444200 by goroutine 22:
  runtime.slicebytetostring()
      /usr/lib/go/src/runtime/string.go:81 +0x0
  github.com/go-resty/resty/v2.(*Request).fmtBodyString()
      /home/buglloc/work/projects/resty/request.go:1037 +0x916
  github.com/go-resty/resty/v2.requestLogger()
      /home/buglloc/work/projects/resty/middleware.go:324 +0x3b0
  github.com/go-resty/resty/v2.(*Client).execute()
      /home/buglloc/work/projects/resty/client.go:1180 +0x84b
  github.com/go-resty/resty/v2.(*Request).Execute()
      /home/buglloc/work/projects/resty/request.go:936 +0x4f9
  github.com/go-resty/resty/v2.(*Request).Post()
      /home/buglloc/work/projects/resty/request.go:862 +0x6ed
  github.com/go-resty/resty/v2.TestDebugLogSimultaneously.func1()
      /home/buglloc/work/projects/resty/client_test.go:784 +0x6cb
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:1742 +0x44

Goroutine 50 (running) created at:
  testing.(*T).Run()
      /usr/lib/go/src/testing/testing.go:1742 +0x825
  github.com/go-resty/resty/v2.TestDebugLogSimultaneously()
      /home/buglloc/work/projects/resty/client_test.go:779 +0x24d
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:1742 +0x44

Goroutine 22 (running) created at:
  testing.(*T).Run()
      /usr/lib/go/src/testing/testing.go:1742 +0x825
  github.com/go-resty/resty/v2.TestDebugLogSimultaneously()
      /home/buglloc/work/projects/resty/client_test.go:779 +0x24d
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:1742 +0x44
==================
==================
WARNING: DATA RACE
Write at 0x00c0007204c0 by goroutine 40:
  runtime.slicecopy()
      /usr/lib/go/src/runtime/slice.go:325 +0x0
  bytes.(*Buffer).Write()
      /usr/lib/go/src/bytes/buffer.go:181 +0x118
  bytes.(*Reader).WriteTo()
      /usr/lib/go/src/bytes/reader.go:143 +0xfe
  io.copyBuffer()
      /usr/lib/go/src/io/io.go:411 +0xd3
  io.Copy()
      /usr/lib/go/src/io/io.go:388 +0x2cc
  github.com/go-resty/resty/v2.getBodyCopy()
      /home/buglloc/work/projects/resty/middleware.go:566 +0x171
  github.com/go-resty/resty/v2.createHTTPRequest()
      /home/buglloc/work/projects/resty/middleware.go:257 +0xe90
  github.com/go-resty/resty/v2.(*Client).execute()
      /home/buglloc/work/projects/resty/client.go:1164 +0x5e5
  github.com/go-resty/resty/v2.(*Request).Execute()
      /home/buglloc/work/projects/resty/request.go:936 +0x4f9
  github.com/go-resty/resty/v2.(*Request).Post()
      /home/buglloc/work/projects/resty/request.go:862 +0x6ed
  github.com/go-resty/resty/v2.TestDebugLogSimultaneously.func1()
      /home/buglloc/work/projects/resty/client_test.go:784 +0x6cb
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:1742 +0x44

Previous read at 0x00c0007204c0 by goroutine 39:
  runtime.slicebytetostring()
      /usr/lib/go/src/runtime/string.go:81 +0x0
  github.com/go-resty/resty/v2.(*Request).fmtBodyString()
      /home/buglloc/work/projects/resty/request.go:1037 +0x916
  github.com/go-resty/resty/v2.requestLogger()
      /home/buglloc/work/projects/resty/middleware.go:324 +0x3b0
  github.com/go-resty/resty/v2.(*Client).execute()
      /home/buglloc/work/projects/resty/client.go:1180 +0x84b
  github.com/go-resty/resty/v2.(*Request).Execute()
      /home/buglloc/work/projects/resty/request.go:936 +0x4f9
  github.com/go-resty/resty/v2.(*Request).Post()
      /home/buglloc/work/projects/resty/request.go:862 +0x6ed
  github.com/go-resty/resty/v2.TestDebugLogSimultaneously.func1()
      /home/buglloc/work/projects/resty/client_test.go:784 +0x6cb
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:1742 +0x44

Goroutine 40 (running) created at:
  testing.(*T).Run()
      /usr/lib/go/src/testing/testing.go:1742 +0x825
  github.com/go-resty/resty/v2.TestDebugLogSimultaneously()
      /home/buglloc/work/projects/resty/client_test.go:779 +0x24d
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:1742 +0x44

Goroutine 39 (running) created at:
  testing.(*T).Run()
      /usr/lib/go/src/testing/testing.go:1742 +0x825
  github.com/go-resty/resty/v2.TestDebugLogSimultaneously()
      /home/buglloc/work/projects/resty/client_test.go:779 +0x24d
  testing.tRunner()
      /usr/lib/go/src/testing/testing.go:1689 +0x21e
  testing.(*T).Run.gowrap1()
      /usr/lib/go/src/testing/testing.go:1742 +0x44
codecov[bot] commented 7 months ago

Codecov Report

Attention: 1 lines in your changes are missing coverage. Please review.

Comparison is base (74050fd) 96.52% compared to head (2b55388) 96.46%. Report is 2 commits behind head on v2.

Files Patch % Lines
request.go 87.50% 1 Missing :warning:
Additional details and impacted files ```diff @@ Coverage Diff @@ ## v2 #775 +/- ## ========================================== - Coverage 96.52% 96.46% -0.06% ========================================== Files 12 12 Lines 1639 1643 +4 ========================================== + Hits 1582 1585 +3 - Misses 36 37 +1 Partials 21 21 ```

:umbrella: View full report in Codecov by Sentry.
:loudspeaker: Have feedback on the report? Share it here.