S3: clone putUserMetadata map to prevent concurrent modification #78

andyasp · 2023-09-20T18:08:38Z

I added CHANGELOG entry for this change.
Change is not relevant to the end user.

Changes

When pulling in the latest objstore in a Mimir PR (grafana/mimir#6061) the tests ran into a data race:

Logs

21:56:02 alertmanager-1: ==================
21:56:02 alertmanager-1: WARNING: DATA RACE
21:56:02 alertmanager-1: Read at 0x00c0007b32f0 by goroutine 524:
21:56:02 alertmanager-1: runtime.mapiterinit()
21:56:02 alertmanager-1: /usr/local/go/src/runtime/map.go:816 +0x0
21:56:02 alertmanager-1: github.com/minio/minio-go/v7.PutObjectOptions.validate()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/minio/minio-go/v7/api-put-object.go:227 +0x66
21:56:02 alertmanager-1: github.com/minio/minio-go/v7.(*Client).PutObject()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/minio/minio-go/v7/api-put-object.go:277 +0x184
21:56:02 alertmanager-1: github.com/thanos-io/objstore/providers/s3.(*Bucket).Upload()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/thanos-io/objstore/providers/s3/s3.go:495 +0x655
21:56:02 alertmanager-1: github.com/thanos-io/objstore.(*metricBucket).Upload()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/thanos-io/objstore/objstore.go:606 +0x328
21:56:02 alertmanager-1: github.com/thanos-io/objstore/tracing/opentracing.(*TracingBucket).Upload.TracingBucket.Upload.func1()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/thanos-io/objstore/tracing/opentracing/opentracing.go:102 +0x18a
21:56:02 alertmanager-1: github.com/thanos-io/objstore/tracing/opentracing.doWithSpan()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/thanos-io/objstore/tracing/opentracing/opentracing.go:215 +0x142
21:56:02 alertmanager-1: github.com/thanos-io/objstore/tracing/opentracing.TracingBucket.Upload()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/thanos-io/objstore/tracing/opentracing/opentracing.go:100 +0x146
21:56:02 alertmanager-1: github.com/thanos-io/objstore/tracing/opentracing.(*TracingBucket).Upload()
21:56:02 alertmanager-1: <autogenerated>:1 +0x29
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/storage/bucket.(*PrefixedBucketClient).Upload()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/storage/bucket/prefixed_bucket_client.go:40 +0xdd
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/storage/bucket.(*PrefixedBucketClient).Upload()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/storage/bucket/prefixed_bucket_client.go:40 +0xdd
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/storage/bucket.(*SSEBucketClient).Upload()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/storage/bucket/sse_bucket_client.go:64 +0x139
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager/alertstore/bucketclient.(*BucketAlertStore).SetFullState()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/alertstore/bucketclient/bucket_client.go:166 +0x161
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*statePersister).persist()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/state_persister.go:130 +0x4cf
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*statePersister).iteration()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/state_persister.go:99 +0x5b
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*statePersister).iteration-fm()
21:56:02 alertmanager-1: <autogenerated>:1 +0x47
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.newStatePersister.NewTimerService.func1()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/services.go:33 +0x195
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).main()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:190 +0x34c
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).StartAsync.func1.2()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:119 +0x33
21:56:02 alertmanager-1: Previous write at 0x00c0007b32f0 by goroutine 454:
21:56:02 alertmanager-1: runtime.mapdelete_faststr()
21:56:02 alertmanager-1: /usr/local/go/src/runtime/map_faststr.go:301 +0x0
21:56:02 alertmanager-1: github.com/minio/minio-go/v7.(*Client).putObjectMultipartStreamNoLength()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/minio/minio-go/v7/api-put-object.go:359 +0x2b8
21:56:02 alertmanager-1: github.com/minio/minio-go/v7.(*Client).putObjectCommon()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/minio/minio-go/v7/api-put-object.go:315 +0x6f7
21:56:02 alertmanager-1: github.com/minio/minio-go/v7.(*Client).PutObject()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/minio/minio-go/v7/api-put-object.go:282 +0x2e4
21:56:02 alertmanager-1: github.com/thanos-io/objstore/providers/s3.(*Bucket).Upload()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/thanos-io/objstore/providers/s3/s3.go:495 +0x655
21:56:02 alertmanager-1: github.com/thanos-io/objstore.(*metricBucket).Upload()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/thanos-io/objstore/objstore.go:606 +0x328
21:56:02 alertmanager-1: github.com/thanos-io/objstore/tracing/opentracing.(*TracingBucket).Upload.TracingBucket.Upload.func1()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/thanos-io/objstore/tracing/opentracing/opentracing.go:102 +0x18a
21:56:02 alertmanager-1: github.com/thanos-io/objstore/tracing/opentracing.doWithSpan()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/thanos-io/objstore/tracing/opentracing/opentracing.go:215 +0x142
21:56:02 alertmanager-1: github.com/thanos-io/objstore/tracing/opentracing.TracingBucket.Upload()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/thanos-io/objstore/tracing/opentracing/opentracing.go:100 +0x146
21:56:02 alertmanager-1: github.com/thanos-io/objstore/tracing/opentracing.(*TracingBucket).Upload()
21:56:02 alertmanager-1: <autogenerated>:1 +0x29
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/storage/bucket.(*PrefixedBucketClient).Upload()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/storage/bucket/prefixed_bucket_client.go:40 +0xdd
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/storage/bucket.(*PrefixedBucketClient).Upload()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/storage/bucket/prefixed_bucket_client.go:40 +0xdd
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/storage/bucket.(*SSEBucketClient).Upload()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/storage/bucket/sse_bucket_client.go:64 +0x139
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager/alertstore/bucketclient.(*BucketAlertStore).SetFullState()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/alertstore/bucketclient/bucket_client.go:166 +0x161
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*statePersister).persist()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/state_persister.go:130 +0x4cf
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*statePersister).iteration()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/state_persister.go:99 +0x5b
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*statePersister).iteration-fm()
21:56:02 alertmanager-1: <autogenerated>:1 +0x47
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.newStatePersister.NewTimerService.func1()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/services.go:33 +0x195
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).main()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:190 +0x34c
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).StartAsync.func1.2()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:119 +0x33
21:56:02 alertmanager-1: Goroutine 524 (running) created at:
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).StartAsync.func1()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:119 +0x1dc
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).switchState()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:139 +0x10b
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).StartAsync()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:116 +0x86
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.New()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/alertmanager.go:236 +0x162a
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*MultitenantAlertmanager).newAlertmanager()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/multitenant.go:774 +0x896
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*MultitenantAlertmanager).setConfig()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/multitenant.go:743 +0x19ad
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*MultitenantAlertmanager).syncConfigs()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/multitenant.go:625 +0x452
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*MultitenantAlertmanager).loadAndSyncConfigs()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/multitenant.go:536 +0x315
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*MultitenantAlertmanager).starting()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/multitenant.go:461 +0x904
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*MultitenantAlertmanager).starting-fm()
21:56:02 alertmanager-1: <autogenerated>:1 +0x47
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).main()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:157 +0xe6
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).StartAsync.func1.2()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:119 +0x33
21:56:02 alertmanager-1: Goroutine 454 (running) created at:
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).StartAsync.func1()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:119 +0x1dc
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).switchState()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:139 +0x10b
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).StartAsync()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:116 +0x86
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.New()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/alertmanager.go:236 +0x162a
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*MultitenantAlertmanager).newAlertmanager()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/multitenant.go:774 +0x896
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*MultitenantAlertmanager).setConfig()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/multitenant.go:743 +0x19ad
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*MultitenantAlertmanager).syncConfigs()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/multitenant.go:625 +0x452
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*MultitenantAlertmanager).loadAndSyncConfigs()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/multitenant.go:536 +0x315
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*MultitenantAlertmanager).starting()
21:56:02 alertmanager-1: /__w/mimir/mimir/pkg/alertmanager/multitenant.go:461 +0x904
21:56:02 alertmanager-1: github.com/grafana/mimir/pkg/alertmanager.(*MultitenantAlertmanager).starting-fm()
21:56:02 alertmanager-1: <autogenerated>:1 +0x47
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).main()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:157 +0xe6
21:56:02 alertmanager-1: github.com/grafana/dskit/services.(*BasicService).StartAsync.func1.2()
21:56:02 alertmanager-1: /__w/mimir/mimir/vendor/github.com/grafana/dskit/services/basic_service.go:119 +0x33
21:56:02 alertmanager-1: ==================

From those logs I determined the race was from concurrent modification to the putUserMetadata map stored in Bucket:

// Bucket implements the store.Bucket interface against s3-compatible APIs.
type Bucket struct {
	logger          log.Logger
	name            string
	client          *minio.Client
	defaultSSE      encrypt.ServerSide
	putUserMetadata map[string]string
	storageClass    string
	partSize        uint64
	listObjectsV1   bool
}

The map is passed directly into the PutObjectOptions from the Bucket struct in s3's Upload:

	if _, err := b.client.PutObject(
		ctx,
		b.name,
		name,
		r,
		size,
		minio.PutObjectOptions{
			PartSize:             partSize,
			ServerSideEncryption: sse,
			UserMetadata:         b.putUserMetadata,
			StorageClass:         b.storageClass,
			// 4 is what minio-go have as the default. To be certain we do micro benchmark before any changes we
			// ensure we pin this number to four.
			// TODO(bwplotka): Consider adjusting this number to GOMAXPROCS or to expose this in config if it becomes bottleneck.
			NumThreads: 4,
		},
	); err != nil {
		return errors.Wrap(err, "upload s3 object")
	}

The problem fixed in #77 caused the upload to be done by minio's putObjectMultipartStreamNoLength, which surpisingly modifies the map passed in by writing/deleting "X-Amz-Checksum-Algorithm".

Verification

Reran the affected test locally with this modification vendored.

yeya24

Thanks!

yeya24 · 2023-09-21T07:12:52Z

Need to fix changelog so that I can merge it. Thanks

Signed-off-by: Andy Asp <andy.asp@grafana.com>

andyasp · 2023-09-21T12:47:00Z

Fixed the conflict, thanks!

fpetkovski · 2023-09-21T13:09:25Z

Thanks @andyasp !

andyasp marked this pull request as ready for review September 20, 2023 18:23

andyasp mentioned this pull request Sep 20, 2023

Update github.com/thanos-io/objstore grafana/mimir#6061

Merged

3 tasks

namco1992 mentioned this pull request Sep 21, 2023

[Compactor] Compactor has concurrent map writes / iterations and writes in v0.32.3 thanos-io/thanos#6742

Closed

yeya24 approved these changes Sep 21, 2023

View reviewed changes

yeya24 mentioned this pull request Sep 21, 2023

Add more duration info to SG request stats log cortexproject/cortex#5573

Merged

3 tasks

andyasp added 2 commits September 21, 2023 08:39

S3: clone putUserMetadata map to prevent concurrent modification

ff39b16

Signed-off-by: Andy Asp <andy.asp@grafana.com>

Add changelog entry

a557e75

Signed-off-by: Andy Asp <andy.asp@grafana.com>

andyasp force-pushed the clone-putUserMetadata branch from d417137 to a557e75 Compare September 21, 2023 12:41

fpetkovski merged commit 63a603e into thanos-io:main Sep 21, 2023
7 checks passed

andyasp deleted the clone-putUserMetadata branch September 21, 2023 13:12

yeya24 mentioned this pull request Sep 21, 2023

Update objstore version to latest thanos-io/thanos#6746

Merged

2 tasks

ZhongRuoyu mentioned this pull request Oct 2, 2023

thanos 0.32.4 Homebrew/homebrew-core#149105

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

S3: clone putUserMetadata map to prevent concurrent modification #78

S3: clone putUserMetadata map to prevent concurrent modification #78

andyasp commented Sep 20, 2023 •

edited

Loading

yeya24 left a comment

yeya24 commented Sep 21, 2023

andyasp commented Sep 21, 2023

fpetkovski commented Sep 21, 2023

S3: clone putUserMetadata map to prevent concurrent modification #78

S3: clone putUserMetadata map to prevent concurrent modification #78

Conversation

andyasp commented Sep 20, 2023 • edited Loading

Changes

Verification

yeya24 left a comment

Choose a reason for hiding this comment

yeya24 commented Sep 21, 2023

andyasp commented Sep 21, 2023

fpetkovski commented Sep 21, 2023

andyasp commented Sep 20, 2023 •

edited

Loading