X-Git-Url: https://git.arvados.org/arvados.git/blobdiff_plain/1127e8884c809a35280d8e57dbe3bc1b8f8818a5..50128b53da4003912635b03fb27b5be2c5beaca1:/services/keepstore/s3_volume.go diff --git a/services/keepstore/s3_volume.go b/services/keepstore/s3_volume.go index ad6ff5bf42..27ac0d9c74 100644 --- a/services/keepstore/s3_volume.go +++ b/services/keepstore/s3_volume.go @@ -1,24 +1,37 @@ package main import ( + "bytes" + "context" "encoding/base64" "encoding/hex" "flag" "fmt" "io" + "io/ioutil" "log" "net/http" "os" "regexp" "strings" + "sync" + "sync/atomic" "time" + "git.curoverse.com/arvados.git/sdk/go/arvados" "github.com/AdRoll/goamz/aws" "github.com/AdRoll/goamz/s3" ) +const ( + s3DefaultReadTimeout = arvados.Duration(10 * time.Minute) + s3DefaultConnectTimeout = arvados.Duration(time.Minute) +) + var ( - ErrS3TrashNotAvailable = fmt.Errorf("trash is not possible because -trash-lifetime=0 and -s3-unsafe-delete=false") + // ErrS3TrashDisabled is returned by Trash if that operation + // is impossible with the current config. + ErrS3TrashDisabled = fmt.Errorf("trash function is disabled because -trash-lifetime=0 and -s3-unsafe-delete=false") s3AccessKeyFile string s3SecretKeyFile string @@ -37,52 +50,36 @@ const ( ) type s3VolumeAdder struct { - *volumeSet + *Config +} + +// String implements flag.Value +func (s *s3VolumeAdder) String() string { + return "-" } func (s *s3VolumeAdder) Set(bucketName string) error { - if trashLifetime != 0 { - return ErrNotImplemented - } if bucketName == "" { return fmt.Errorf("no container name given") } if s3AccessKeyFile == "" || s3SecretKeyFile == "" { return fmt.Errorf("-s3-access-key-file and -s3-secret-key-file arguments must given before -s3-bucket-volume") } - region, ok := aws.Regions[s3RegionName] - if s3Endpoint == "" { - if !ok { - return fmt.Errorf("unrecognized region %+q; try specifying -s3-endpoint instead", s3RegionName) - } - } else { - if ok { - return fmt.Errorf("refusing to use AWS region name %+q with endpoint %+q; "+ - "specify empty endpoint (\"-s3-endpoint=\") or use a different region name", s3RegionName, s3Endpoint) - } - region = aws.Region{ - Name: s3RegionName, - S3Endpoint: s3Endpoint, - } - } - var err error - var auth aws.Auth - auth.AccessKey, err = readKeyFromFile(s3AccessKeyFile) - if err != nil { - return err - } - auth.SecretKey, err = readKeyFromFile(s3SecretKeyFile) - if err != nil { - return err - } - if flagSerializeIO { + if deprecated.flagSerializeIO { log.Print("Notice: -serialize is not supported by s3-bucket volumes.") } - v := NewS3Volume(auth, region, bucketName, s3RaceWindow, flagReadonly, s3Replication) - if err := v.Check(); err != nil { - return err - } - *s.volumeSet = append(*s.volumeSet, v) + s.Config.Volumes = append(s.Config.Volumes, &S3Volume{ + Bucket: bucketName, + AccessKeyFile: s3AccessKeyFile, + SecretKeyFile: s3SecretKeyFile, + Endpoint: s3Endpoint, + Region: s3RegionName, + RaceWindow: arvados.Duration(s3RaceWindow), + S3Replication: s3Replication, + UnsafeDelete: s3UnsafeDelete, + ReadOnly: deprecated.flagReadonly, + IndexPageSize: 1000, + }) return nil } @@ -94,7 +91,9 @@ func s3regions() (okList []string) { } func init() { - flag.Var(&s3VolumeAdder{&volumes}, + VolumeTypes = append(VolumeTypes, func() VolumeWithExamples { return &S3Volume{} }) + + flag.Var(&s3VolumeAdder{theConfig}, "s3-bucket-volume", "Use the given bucket as a storage volume. Can be given multiple times.") flag.StringVar( @@ -111,12 +110,12 @@ func init() { &s3AccessKeyFile, "s3-access-key-file", "", - "File containing the access key used for subsequent -s3-bucket-volume arguments.") + "`File` containing the access key used for subsequent -s3-bucket-volume arguments.") flag.StringVar( &s3SecretKeyFile, "s3-secret-key-file", "", - "File containing the secret key used for subsequent -s3-bucket-volume arguments.") + "`File` containing the secret key used for subsequent -s3-bucket-volume arguments.") flag.DurationVar( &s3RaceWindow, "s3-race-window", @@ -134,41 +133,147 @@ func init() { "EXPERIMENTAL. Enable deletion (garbage collection), even though there are known race conditions that can cause data loss.") } +// S3Volume implements Volume using an S3 bucket. type S3Volume struct { - *s3.Bucket - raceWindow time.Duration - readonly bool - replication int - indexPageSize int + AccessKeyFile string + SecretKeyFile string + Endpoint string + Region string + Bucket string + LocationConstraint bool + IndexPageSize int + S3Replication int + ConnectTimeout arvados.Duration + ReadTimeout arvados.Duration + RaceWindow arvados.Duration + ReadOnly bool + UnsafeDelete bool + + bucket *s3bucket + + startOnce sync.Once +} + +// Examples implements VolumeWithExamples. +func (*S3Volume) Examples() []Volume { + return []Volume{ + &S3Volume{ + AccessKeyFile: "/etc/aws_s3_access_key.txt", + SecretKeyFile: "/etc/aws_s3_secret_key.txt", + Endpoint: "", + Region: "us-east-1", + Bucket: "example-bucket-name", + IndexPageSize: 1000, + S3Replication: 2, + RaceWindow: arvados.Duration(24 * time.Hour), + ConnectTimeout: arvados.Duration(time.Minute), + ReadTimeout: arvados.Duration(5 * time.Minute), + }, + &S3Volume{ + AccessKeyFile: "/etc/gce_s3_access_key.txt", + SecretKeyFile: "/etc/gce_s3_secret_key.txt", + Endpoint: "https://storage.googleapis.com", + Region: "", + Bucket: "example-bucket-name", + IndexPageSize: 1000, + S3Replication: 2, + RaceWindow: arvados.Duration(24 * time.Hour), + ConnectTimeout: arvados.Duration(time.Minute), + ReadTimeout: arvados.Duration(5 * time.Minute), + }, + } } -// NewS3Volume returns a new S3Volume using the given auth, region, -// and bucket name. The replication argument specifies the replication -// level to report when writing data. -func NewS3Volume(auth aws.Auth, region aws.Region, bucket string, raceWindow time.Duration, readonly bool, replication int) *S3Volume { - return &S3Volume{ +// Type implements Volume. +func (*S3Volume) Type() string { + return "S3" +} + +// Start populates private fields and verifies the configuration is +// valid. +func (v *S3Volume) Start() error { + region, ok := aws.Regions[v.Region] + if v.Endpoint == "" { + if !ok { + return fmt.Errorf("unrecognized region %+q; try specifying -s3-endpoint instead", v.Region) + } + } else if ok { + return fmt.Errorf("refusing to use AWS region name %+q with endpoint %+q; "+ + "specify empty endpoint (\"-s3-endpoint=\") or use a different region name", v.Region, v.Endpoint) + } else { + region = aws.Region{ + Name: v.Region, + S3Endpoint: v.Endpoint, + S3LocationConstraint: v.LocationConstraint, + } + } + + var err error + var auth aws.Auth + auth.AccessKey, err = readKeyFromFile(v.AccessKeyFile) + if err != nil { + return err + } + auth.SecretKey, err = readKeyFromFile(v.SecretKeyFile) + if err != nil { + return err + } + + // Zero timeouts mean "wait forever", which is a bad + // default. Default to long timeouts instead. + if v.ConnectTimeout == 0 { + v.ConnectTimeout = s3DefaultConnectTimeout + } + if v.ReadTimeout == 0 { + v.ReadTimeout = s3DefaultReadTimeout + } + + client := s3.New(auth, region) + client.ConnectTimeout = time.Duration(v.ConnectTimeout) + client.ReadTimeout = time.Duration(v.ReadTimeout) + v.bucket = &s3bucket{ Bucket: &s3.Bucket{ - S3: s3.New(auth, region), - Name: bucket, + S3: client, + Name: v.Bucket, }, - raceWindow: raceWindow, - readonly: readonly, - replication: replication, - indexPageSize: 1000, } + return nil } -func (v *S3Volume) Check() error { - return nil +func (v *S3Volume) getReaderWithContext(ctx context.Context, loc string) (rdr io.ReadCloser, err error) { + ready := make(chan bool) + go func() { + rdr, err = v.getReader(loc) + close(ready) + }() + select { + case <-ready: + return + case <-ctx.Done(): + theConfig.debugLogf("s3: abandoning getReader(): %s", ctx.Err()) + go func() { + <-ready + if err == nil { + rdr.Close() + } + }() + return nil, ctx.Err() + } } -func (v *S3Volume) getReaderWithFixRace(loc string) (rdr io.ReadCloser, err error) { - rdr, err = v.Bucket.GetReader(loc) +// getReader wraps (Bucket)GetReader. +// +// In situations where (Bucket)GetReader would fail because the block +// disappeared in a Trash race, getReader calls fixRace to recover the +// data, and tries again. +func (v *S3Volume) getReader(loc string) (rdr io.ReadCloser, err error) { + rdr, err = v.bucket.GetReader(loc) err = v.translateError(err) if err == nil || !os.IsNotExist(err) { return } - _, err = v.Bucket.Head("recent/"+loc, nil) + + _, err = v.bucket.Head("recent/"+loc, nil) err = v.translateError(err) if err != nil { // If we can't read recent/X, there's no point in @@ -179,7 +284,8 @@ func (v *S3Volume) getReaderWithFixRace(loc string) (rdr io.ReadCloser, err erro err = os.ErrNotExist return } - rdr, err = v.Bucket.GetReader(loc) + + rdr, err = v.bucket.GetReader(loc) if err != nil { log.Printf("warning: reading %s after successful fixRace: %s", loc, err) err = v.translateError(err) @@ -187,55 +293,116 @@ func (v *S3Volume) getReaderWithFixRace(loc string) (rdr io.ReadCloser, err erro return } -func (v *S3Volume) Get(loc string, buf []byte) (int, error) { - rdr, err := v.getReaderWithFixRace(loc) +// Get a block: copy the block data into buf, and return the number of +// bytes copied. +func (v *S3Volume) Get(ctx context.Context, loc string, buf []byte) (int, error) { + rdr, err := v.getReaderWithContext(ctx, loc) if err != nil { return 0, err } - defer rdr.Close() - n, err := io.ReadFull(rdr, buf) - switch err { - case nil, io.EOF, io.ErrUnexpectedEOF: - return n, nil - default: - return 0, v.translateError(err) - } -} -func (v *S3Volume) Compare(loc string, expect []byte) error { - rdr, err := v.getReaderWithFixRace(loc) + var n int + ready := make(chan bool) + go func() { + defer close(ready) + + defer rdr.Close() + n, err = io.ReadFull(rdr, buf) + + switch err { + case nil, io.EOF, io.ErrUnexpectedEOF: + err = nil + default: + err = v.translateError(err) + } + }() + select { + case <-ctx.Done(): + theConfig.debugLogf("s3: interrupting ReadFull() with Close() because %s", ctx.Err()) + rdr.Close() + // Must wait for ReadFull to return, to ensure it + // doesn't write to buf after we return. + theConfig.debugLogf("s3: waiting for ReadFull() to fail") + <-ready + return 0, ctx.Err() + case <-ready: + return n, err + } +} + +// Compare the given data with the stored data. +func (v *S3Volume) Compare(ctx context.Context, loc string, expect []byte) error { + rdr, err := v.getReaderWithContext(ctx, loc) if err != nil { return err } defer rdr.Close() - return v.translateError(compareReaderWithBuf(rdr, expect, loc[:32])) + return v.translateError(compareReaderWithBuf(ctx, rdr, expect, loc[:32])) } -func (v *S3Volume) Put(loc string, block []byte) error { - if v.readonly { +// Put writes a block. +func (v *S3Volume) Put(ctx context.Context, loc string, block []byte) error { + if v.ReadOnly { return MethodDisabledError } var opts s3.Options - if len(block) > 0 { + size := len(block) + if size > 0 { md5, err := hex.DecodeString(loc) if err != nil { return err } opts.ContentMD5 = base64.StdEncoding.EncodeToString(md5) } - err := v.Bucket.Put(loc, block, "application/octet-stream", s3ACL, opts) - if err != nil { + + // Send the block data through a pipe, so that (if we need to) + // we can close the pipe early and abandon our PutReader() + // goroutine, without worrying about PutReader() accessing our + // block buffer after we release it. + bufr, bufw := io.Pipe() + go func() { + io.Copy(bufw, bytes.NewReader(block)) + bufw.Close() + }() + + var err error + ready := make(chan bool) + go func() { + defer func() { + if ctx.Err() != nil { + theConfig.debugLogf("%s: abandoned PutReader goroutine finished with err: %s", v, err) + } + }() + defer close(ready) + err = v.bucket.PutReader(loc, bufr, int64(size), "application/octet-stream", s3ACL, opts) + if err != nil { + return + } + err = v.bucket.Put("recent/"+loc, nil, "application/octet-stream", s3ACL, s3.Options{}) + }() + select { + case <-ctx.Done(): + theConfig.debugLogf("%s: taking PutReader's input away: %s", v, ctx.Err()) + // Our pipe might be stuck in Write(), waiting for + // io.Copy() to read. If so, un-stick it. This means + // PutReader will get corrupt data, but that's OK: the + // size and MD5 won't match, so the write will fail. + go io.Copy(ioutil.Discard, bufr) + // CloseWithError() will return once pending I/O is done. + bufw.CloseWithError(ctx.Err()) + theConfig.debugLogf("%s: abandoning PutReader goroutine", v) + return ctx.Err() + case <-ready: return v.translateError(err) } - err = v.Bucket.Put("recent/"+loc, nil, "application/octet-stream", s3ACL, s3.Options{}) - return v.translateError(err) } +// Touch sets the timestamp for the given locator to the current time. func (v *S3Volume) Touch(loc string) error { - if v.readonly { + if v.ReadOnly { return MethodDisabledError } - _, err := v.Bucket.Head(loc, nil) + _, err := v.bucket.Head(loc, nil) err = v.translateError(err) if os.IsNotExist(err) && v.fixRace(loc) { // The data object got trashed in a race, but fixRace @@ -243,26 +410,27 @@ func (v *S3Volume) Touch(loc string) error { } else if err != nil { return err } - err = v.Bucket.Put("recent/"+loc, nil, "application/octet-stream", s3ACL, s3.Options{}) + err = v.bucket.Put("recent/"+loc, nil, "application/octet-stream", s3ACL, s3.Options{}) return v.translateError(err) } +// Mtime returns the stored timestamp for the given locator. func (v *S3Volume) Mtime(loc string) (time.Time, error) { - _, err := v.Bucket.Head(loc, nil) + _, err := v.bucket.Head(loc, nil) if err != nil { return zeroTime, v.translateError(err) } - resp, err := v.Bucket.Head("recent/"+loc, nil) + resp, err := v.bucket.Head("recent/"+loc, nil) err = v.translateError(err) if os.IsNotExist(err) { // The data object X exists, but recent/X is missing. - err = v.Bucket.Put("recent/"+loc, nil, "application/octet-stream", s3ACL, s3.Options{}) + err = v.bucket.Put("recent/"+loc, nil, "application/octet-stream", s3ACL, s3.Options{}) if err != nil { log.Printf("error: creating %q: %s", "recent/"+loc, err) return zeroTime, v.translateError(err) } log.Printf("info: created %q to migrate existing block to new storage scheme", "recent/"+loc) - resp, err = v.Bucket.Head("recent/"+loc, nil) + resp, err = v.bucket.Head("recent/"+loc, nil) if err != nil { log.Printf("error: created %q but HEAD failed: %s", "recent/"+loc, err) return zeroTime, v.translateError(err) @@ -274,19 +442,24 @@ func (v *S3Volume) Mtime(loc string) (time.Time, error) { return v.lastModified(resp) } +// IndexTo writes a complete list of locators with the given prefix +// for which Get() can retrieve data. func (v *S3Volume) IndexTo(prefix string, writer io.Writer) error { // Use a merge sort to find matching sets of X and recent/X. dataL := s3Lister{ - Bucket: v.Bucket, + Bucket: v.bucket.Bucket, Prefix: prefix, - PageSize: v.indexPageSize, + PageSize: v.IndexPageSize, } recentL := s3Lister{ - Bucket: v.Bucket, - Prefix: "recent/"+prefix, - PageSize: v.indexPageSize, + Bucket: v.bucket.Bucket, + Prefix: "recent/" + prefix, + PageSize: v.IndexPageSize, } + v.bucket.stats.tick(&v.bucket.stats.Ops, &v.bucket.stats.ListOps) + v.bucket.stats.tick(&v.bucket.stats.Ops, &v.bucket.stats.ListOps) for data, recent := dataL.First(), recentL.First(); data != nil; data = dataL.Next() { + v.bucket.stats.tick(&v.bucket.stats.Ops, &v.bucket.stats.ListOps) if data.Key >= "g" { // Conveniently, "recent/*" and "trash/*" are // lexically greater than all hex-encoded data @@ -308,10 +481,12 @@ func (v *S3Volume) IndexTo(prefix string, writer io.Writer) error { for recent != nil { if cmp := strings.Compare(recent.Key[7:], data.Key); cmp < 0 { recent = recentL.Next() + v.bucket.stats.tick(&v.bucket.stats.Ops, &v.bucket.stats.ListOps) continue } else if cmp == 0 { stamp = recent recent = recentL.Next() + v.bucket.stats.tick(&v.bucket.stats.Ops, &v.bucket.stats.ListOps) break } else { // recent/X marker is missing: we'll @@ -331,58 +506,72 @@ func (v *S3Volume) IndexTo(prefix string, writer io.Writer) error { // Trash a Keep block. func (v *S3Volume) Trash(loc string) error { - if v.readonly { + if v.ReadOnly { return MethodDisabledError } if t, err := v.Mtime(loc); err != nil { return err - } else if time.Since(t) < blobSignatureTTL { + } else if time.Since(t) < theConfig.BlobSignatureTTL.Duration() { return nil } - if trashLifetime == 0 { + if theConfig.TrashLifetime == 0 { if !s3UnsafeDelete { - return ErrS3TrashNotAvailable + return ErrS3TrashDisabled } - return v.Bucket.Del(loc) + return v.translateError(v.bucket.Del(loc)) } - - // Make sure we're not in the race window. - { - resp, err := v.Bucket.Head("trash/"+loc, nil) - err = v.translateError(err) - if os.IsNotExist(err) { - // OK, trash/X doesn't exist so we're not in - // the race window - } else if err != nil { - // Error looking up trash/X. Unsafe to proceed - // without knowing whether we're in the race - // window - return err - } else if t, err := v.lastModified(resp); err != nil { - // Can't parse timestamp - return err - } else if safeWindow := t.Add(trashLifetime).Sub(time.Now().Add(v.raceWindow)); safeWindow <= 0 { - // We can't count on "touch trash/X" to - // prolong trash/X's lifetime. The new - // timestamp might not become visible until - // now+raceWindow, and EmptyTrash is allowed - // to delete trash/X before then. - return fmt.Errorf("same block is already in trash, and safe window ended %s ago", -safeWindow) - } + err := v.checkRaceWindow(loc) + if err != nil { + return err } + err = v.safeCopy("trash/"+loc, loc) + if err != nil { + return err + } + return v.translateError(v.bucket.Del(loc)) +} - err := v.safeCopy("trash/"+loc, loc) +// checkRaceWindow returns a non-nil error if trash/loc is, or might +// be, in the race window (i.e., it's not safe to trash loc). +func (v *S3Volume) checkRaceWindow(loc string) error { + resp, err := v.bucket.Head("trash/"+loc, nil) + err = v.translateError(err) + if os.IsNotExist(err) { + // OK, trash/X doesn't exist so we're not in the race + // window + return nil + } else if err != nil { + // Error looking up trash/X. We don't know whether + // we're in the race window + return err + } + t, err := v.lastModified(resp) if err != nil { + // Can't parse timestamp return err } - return v.translateError(v.Bucket.Del(loc)) + safeWindow := t.Add(theConfig.TrashLifetime.Duration()).Sub(time.Now().Add(time.Duration(v.RaceWindow))) + if safeWindow <= 0 { + // We can't count on "touch trash/X" to prolong + // trash/X's lifetime. The new timestamp might not + // become visible until now+raceWindow, and EmptyTrash + // is allowed to delete trash/X before then. + return fmt.Errorf("same block is already in trash, and safe window ended %s ago", -safeWindow) + } + // trash/X exists, but it won't be eligible for deletion until + // after now+raceWindow, so it's safe to overwrite it. + return nil } +// safeCopy calls PutCopy, and checks the response to make sure the +// copy succeeded and updated the timestamp on the destination object +// (PutCopy returns 200 OK if the request was received, even if the +// copy failed). func (v *S3Volume) safeCopy(dst, src string) error { - resp, err := v.Bucket.PutCopy(dst, s3ACL, s3.CopyOptions{ + resp, err := v.bucket.PutCopy(dst, s3ACL, s3.CopyOptions{ ContentType: "application/octet-stream", MetadataDirective: "REPLACE", - }, v.Bucket.Name+"/"+src) + }, v.bucket.Name+"/"+src) err = v.translateError(err) if err != nil { return err @@ -411,10 +600,19 @@ func (v *S3Volume) lastModified(resp *http.Response) (t time.Time, err error) { return } +// Untrash moves block from trash back into store func (v *S3Volume) Untrash(loc string) error { - return v.safeCopy(loc, "trash/"+loc) + err := v.safeCopy(loc, "trash/"+loc) + if err != nil { + return err + } + err = v.bucket.Put("recent/"+loc, nil, "application/octet-stream", s3ACL, s3.Options{}) + return v.translateError(err) } +// Status returns a *VolumeStatus representing the current in-use +// storage capacity and a fake available capacity that doesn't make +// the volume seem full or nearly-full. func (v *S3Volume) Status() *VolumeStatus { return &VolumeStatus{ DeviceNum: 1, @@ -423,15 +621,26 @@ func (v *S3Volume) Status() *VolumeStatus { } } +// InternalStats returns bucket I/O and API call counters. +func (v *S3Volume) InternalStats() interface{} { + return &v.bucket.stats +} + +// String implements fmt.Stringer. func (v *S3Volume) String() string { - return fmt.Sprintf("s3-bucket:%+q", v.Bucket.Name) + return fmt.Sprintf("s3-bucket:%+q", v.Bucket) } +// Writable returns false if all future Put, Mtime, and Delete calls +// are expected to fail. func (v *S3Volume) Writable() bool { - return !v.readonly + return !v.ReadOnly } + +// Replication returns the storage redundancy of the underlying +// device. Configured via command line flag. func (v *S3Volume) Replication() int { - return v.replication + return v.S3Replication } var s3KeepBlockRegexp = regexp.MustCompile(`^[0-9a-f]{32}$`) @@ -445,7 +654,7 @@ func (v *S3Volume) isKeepBlock(s string) bool { // there was a race between Put and Trash, fixRace recovers from the // race by Untrashing the block. func (v *S3Volume) fixRace(loc string) bool { - trash, err := v.Bucket.Head("trash/"+loc, nil) + trash, err := v.bucket.Head("trash/"+loc, nil) if err != nil { if !os.IsNotExist(v.translateError(err)) { log.Printf("error: fixRace: HEAD %q: %s", "trash/"+loc, err) @@ -458,7 +667,7 @@ func (v *S3Volume) fixRace(loc string) bool { return false } - recent, err := v.Bucket.Head("recent/"+loc, nil) + recent, err := v.bucket.Head("recent/"+loc, nil) if err != nil { log.Printf("error: fixRace: HEAD %q: %s", "recent/"+loc, err) return false @@ -470,13 +679,13 @@ func (v *S3Volume) fixRace(loc string) bool { } ageWhenTrashed := trashTime.Sub(recentTime) - if ageWhenTrashed >= blobSignatureTTL { + if ageWhenTrashed >= theConfig.BlobSignatureTTL.Duration() { // No evidence of a race: block hasn't been written // since it became eligible for Trash. No fix needed. return false } - log.Printf("notice: fixRace: %q: trashed at %s but touched at %s (age when trashed = %s < %s)", loc, trashTime, recentTime, ageWhenTrashed, blobSignatureTTL) + log.Printf("notice: fixRace: %q: trashed at %s but touched at %s (age when trashed = %s < %s)", loc, trashTime, recentTime, ageWhenTrashed, theConfig.BlobSignatureTTL) log.Printf("notice: fixRace: copying %q to %q to recover from race between Put/Touch and Trash", "recent/"+loc, loc) err = v.safeCopy(loc, "trash/"+loc) if err != nil { @@ -501,50 +710,88 @@ func (v *S3Volume) translateError(err error) error { return err } -// EmptyTrash looks for trashed blocks that exceeded trashLifetime +// EmptyTrash looks for trashed blocks that exceeded TrashLifetime // and deletes them from the volume. func (v *S3Volume) EmptyTrash() { + var bytesInTrash, blocksInTrash, bytesDeleted, blocksDeleted int64 + // Use a merge sort to find matching sets of trash/X and recent/X. trashL := s3Lister{ - Bucket: v.Bucket, + Bucket: v.bucket.Bucket, Prefix: "trash/", - PageSize: v.indexPageSize, + PageSize: v.IndexPageSize, } // Define "ready to delete" as "...when EmptyTrash started". - now := time.Now() + startT := time.Now() for trash := trashL.First(); trash != nil; trash = trashL.Next() { loc := trash.Key[6:] if !v.isKeepBlock(loc) { continue } - recent, err := v.Bucket.Head("recent/"+loc, nil) + bytesInTrash += trash.Size + blocksInTrash++ + + trashT, err := time.Parse(time.RFC3339, trash.LastModified) if err != nil { - log.Printf("warning: %s: EmptyTrash: cannot delete trash %q with no corresponding recent/* marker", v, trash.Key) + log.Printf("warning: %s: EmptyTrash: %q: parse %q: %s", v, trash.Key, trash.LastModified, err) continue } - trashT, err := time.Parse(time.RFC3339, trash.LastModified) - if err != nil { + recent, err := v.bucket.Head("recent/"+loc, nil) + if err != nil && os.IsNotExist(v.translateError(err)) { + log.Printf("warning: %s: EmptyTrash: found trash marker %q but no %q (%s); calling Untrash", v, trash.Key, "recent/"+loc, err) + err = v.Untrash(loc) + if err != nil { + log.Printf("error: %s: EmptyTrash: Untrash(%q): %s", v, loc, err) + } + continue + } else if err != nil { + log.Printf("warning: %s: EmptyTrash: HEAD %q: %s", v, "recent/"+loc, err) continue } recentT, err := v.lastModified(recent) if err != nil { + log.Printf("warning: %s: EmptyTrash: %q: parse %q: %s", v, "recent/"+loc, recent.Header.Get("Last-Modified"), err) continue } - if trashT.Sub(recentT) < blobSignatureTTL { - v.fixRace(loc) - continue + if trashT.Sub(recentT) < theConfig.BlobSignatureTTL.Duration() { + if age := startT.Sub(recentT); age >= theConfig.BlobSignatureTTL.Duration()-time.Duration(v.RaceWindow) { + // recent/loc is too old to protect + // loc from being Trashed again during + // the raceWindow that starts if we + // delete trash/X now. + // + // Note this means (TrashCheckInterval + // < BlobSignatureTTL - raceWindow) is + // necessary to avoid starvation. + log.Printf("notice: %s: EmptyTrash: detected old race for %q, calling fixRace + Touch", v, loc) + v.fixRace(loc) + v.Touch(loc) + continue + } + _, err := v.bucket.Head(loc, nil) + if os.IsNotExist(err) { + log.Printf("notice: %s: EmptyTrash: detected recent race for %q, calling fixRace", v, loc) + v.fixRace(loc) + continue + } else if err != nil { + log.Printf("warning: %s: EmptyTrash: HEAD %q: %s", v, loc, err) + continue + } } - if now.Sub(trashT) < trashLifetime { + if startT.Sub(trashT) < theConfig.TrashLifetime.Duration() { continue } - err = v.Bucket.Del(trash.Key) + err = v.bucket.Del(trash.Key) if err != nil { log.Printf("warning: %s: EmptyTrash: deleting %q: %s", v, trash.Key, err) continue } - _, err = v.Bucket.Head(loc, nil) + bytesDeleted += trash.Size + blocksDeleted++ + + _, err = v.bucket.Head(loc, nil) if os.IsNotExist(err) { - err = v.Bucket.Del("recent/"+loc) + err = v.bucket.Del("recent/" + loc) if err != nil { log.Printf("warning: %s: EmptyTrash: deleting %q: %s", v, "recent/"+loc, err) } @@ -555,15 +802,16 @@ func (v *S3Volume) EmptyTrash() { if err := trashL.Error(); err != nil { log.Printf("error: %s: EmptyTrash: lister: %s", v, err) } + log.Printf("EmptyTrash stats for %v: Deleted %v bytes in %v blocks. Remaining in trash: %v bytes in %v blocks.", v.String(), bytesDeleted, blocksDeleted, bytesInTrash-bytesDeleted, blocksInTrash-blocksDeleted) } type s3Lister struct { - Bucket *s3.Bucket - Prefix string - PageSize int - nextMarker string - buf []s3.Key - err error + Bucket *s3.Bucket + Prefix string + PageSize int + nextMarker string + buf []s3.Key + err error } // First fetches the first page and returns the first item. It returns @@ -615,3 +863,91 @@ func (lister *s3Lister) pop() (k *s3.Key) { } return } + +// s3bucket wraps s3.bucket and counts I/O and API usage stats. +type s3bucket struct { + *s3.Bucket + stats s3bucketStats +} + +func (b *s3bucket) GetReader(path string) (io.ReadCloser, error) { + rdr, err := b.Bucket.GetReader(path) + b.stats.tick(&b.stats.Ops, &b.stats.GetOps) + b.stats.tickErr(err) + return NewCountingReader(rdr, b.stats.tickInBytes), err +} + +func (b *s3bucket) Head(path string, headers map[string][]string) (*http.Response, error) { + resp, err := b.Bucket.Head(path, headers) + b.stats.tick(&b.stats.Ops, &b.stats.HeadOps) + b.stats.tickErr(err) + return resp, err +} + +func (b *s3bucket) PutReader(path string, r io.Reader, length int64, contType string, perm s3.ACL, options s3.Options) error { + err := b.Bucket.PutReader(path, NewCountingReader(r, b.stats.tickOutBytes), length, contType, perm, options) + b.stats.tick(&b.stats.Ops, &b.stats.PutOps) + b.stats.tickErr(err) + return err +} + +func (b *s3bucket) Put(path string, data []byte, contType string, perm s3.ACL, options s3.Options) error { + err := b.Bucket.PutReader(path, NewCountingReader(bytes.NewBuffer(data), b.stats.tickOutBytes), int64(len(data)), contType, perm, options) + b.stats.tick(&b.stats.Ops, &b.stats.PutOps) + b.stats.tickErr(err) + return err +} + +func (b *s3bucket) Del(path string) error { + err := b.Bucket.Del(path) + b.stats.tick(&b.stats.Ops, &b.stats.DelOps) + b.stats.tickErr(err) + return err +} + +type s3bucketStats struct { + Errors uint64 + Ops uint64 + GetOps uint64 + PutOps uint64 + HeadOps uint64 + DelOps uint64 + ListOps uint64 + InBytes uint64 + OutBytes uint64 + + ErrorCodes map[string]uint64 `json:",omitempty"` + + lock sync.Mutex +} + +func (s *s3bucketStats) tickInBytes(n uint64) { + atomic.AddUint64(&s.InBytes, n) +} + +func (s *s3bucketStats) tickOutBytes(n uint64) { + atomic.AddUint64(&s.OutBytes, n) +} + +func (s *s3bucketStats) tick(counters ...*uint64) { + for _, counter := range counters { + atomic.AddUint64(counter, 1) + } +} + +func (s *s3bucketStats) tickErr(err error) { + if err == nil { + return + } + atomic.AddUint64(&s.Errors, 1) + errStr := fmt.Sprintf("%T", err) + if err, ok := err.(*s3.Error); ok { + errStr = errStr + fmt.Sprintf(" %d %s", err.StatusCode, err.Code) + } + s.lock.Lock() + if s.ErrorCodes == nil { + s.ErrorCodes = make(map[string]uint64) + } + s.ErrorCodes[errStr]++ + s.lock.Unlock() +}