18874: Merge commit '6f8dcb2b13f3058db656908fb26b09e23b527f08' into 18874-merge-wb2
[arvados.git] / services / keepstore / unix_volume.go
1 // Copyright (C) The Arvados Authors. All rights reserved.
2 //
3 // SPDX-License-Identifier: AGPL-3.0
4
5 package keepstore
6
7 import (
8         "context"
9         "encoding/json"
10         "errors"
11         "fmt"
12         "io"
13         "io/ioutil"
14         "os"
15         "os/exec"
16         "path/filepath"
17         "regexp"
18         "strconv"
19         "strings"
20         "sync"
21         "sync/atomic"
22         "syscall"
23         "time"
24
25         "git.arvados.org/arvados.git/sdk/go/arvados"
26         "github.com/prometheus/client_golang/prometheus"
27         "github.com/sirupsen/logrus"
28 )
29
30 func init() {
31         driver["Directory"] = newDirectoryVolume
32 }
33
34 func newDirectoryVolume(cluster *arvados.Cluster, volume arvados.Volume, logger logrus.FieldLogger, metrics *volumeMetricsVecs) (Volume, error) {
35         v := &UnixVolume{cluster: cluster, volume: volume, logger: logger, metrics: metrics}
36         err := json.Unmarshal(volume.DriverParameters, &v)
37         if err != nil {
38                 return nil, err
39         }
40         v.logger = v.logger.WithField("Volume", v.String())
41         return v, v.check()
42 }
43
44 func (v *UnixVolume) check() error {
45         if v.Root == "" {
46                 return errors.New("DriverParameters.Root was not provided")
47         }
48         if v.Serialize {
49                 v.locker = &sync.Mutex{}
50         }
51         if !strings.HasPrefix(v.Root, "/") {
52                 return fmt.Errorf("DriverParameters.Root %q does not start with '/'", v.Root)
53         }
54
55         // Set up prometheus metrics
56         lbls := prometheus.Labels{"device_id": v.GetDeviceID()}
57         v.os.stats.opsCounters, v.os.stats.errCounters, v.os.stats.ioBytes = v.metrics.getCounterVecsFor(lbls)
58
59         _, err := v.os.Stat(v.Root)
60         return err
61 }
62
63 // A UnixVolume stores and retrieves blocks in a local directory.
64 type UnixVolume struct {
65         Root      string // path to the volume's root directory
66         Serialize bool
67
68         cluster *arvados.Cluster
69         volume  arvados.Volume
70         logger  logrus.FieldLogger
71         metrics *volumeMetricsVecs
72
73         // something to lock during IO, typically a sync.Mutex (or nil
74         // to skip locking)
75         locker sync.Locker
76
77         os osWithStats
78 }
79
80 // GetDeviceID returns a globally unique ID for the volume's root
81 // directory, consisting of the filesystem's UUID and the path from
82 // filesystem root to storage directory, joined by "/". For example,
83 // the device ID for a local directory "/mnt/xvda1/keep" might be
84 // "fa0b6166-3b55-4994-bd3f-92f4e00a1bb0/keep".
85 func (v *UnixVolume) GetDeviceID() string {
86         giveup := func(f string, args ...interface{}) string {
87                 v.logger.Infof(f+"; using blank DeviceID for volume %s", append(args, v)...)
88                 return ""
89         }
90         buf, err := exec.Command("findmnt", "--noheadings", "--target", v.Root).CombinedOutput()
91         if err != nil {
92                 return giveup("findmnt: %s (%q)", err, buf)
93         }
94         findmnt := strings.Fields(string(buf))
95         if len(findmnt) < 2 {
96                 return giveup("could not parse findmnt output: %q", buf)
97         }
98         fsRoot, dev := findmnt[0], findmnt[1]
99
100         absRoot, err := filepath.Abs(v.Root)
101         if err != nil {
102                 return giveup("resolving relative path %q: %s", v.Root, err)
103         }
104         realRoot, err := filepath.EvalSymlinks(absRoot)
105         if err != nil {
106                 return giveup("resolving symlinks in %q: %s", absRoot, err)
107         }
108
109         // Find path from filesystem root to realRoot
110         var fsPath string
111         if strings.HasPrefix(realRoot, fsRoot+"/") {
112                 fsPath = realRoot[len(fsRoot):]
113         } else if fsRoot == "/" {
114                 fsPath = realRoot
115         } else if fsRoot == realRoot {
116                 fsPath = ""
117         } else {
118                 return giveup("findmnt reports mount point %q which is not a prefix of volume root %q", fsRoot, realRoot)
119         }
120
121         if !strings.HasPrefix(dev, "/") {
122                 return giveup("mount %q device %q is not a path", fsRoot, dev)
123         }
124
125         fi, err := os.Stat(dev)
126         if err != nil {
127                 return giveup("stat %q: %s", dev, err)
128         }
129         ino := fi.Sys().(*syscall.Stat_t).Ino
130
131         // Find a symlink in /dev/disk/by-uuid/ whose target is (i.e.,
132         // has the same inode as) the mounted device
133         udir := "/dev/disk/by-uuid"
134         d, err := os.Open(udir)
135         if err != nil {
136                 return giveup("opening %q: %s", udir, err)
137         }
138         defer d.Close()
139         uuids, err := d.Readdirnames(0)
140         if err != nil {
141                 return giveup("reading %q: %s", udir, err)
142         }
143         for _, uuid := range uuids {
144                 link := filepath.Join(udir, uuid)
145                 fi, err = os.Stat(link)
146                 if err != nil {
147                         v.logger.WithError(err).Errorf("stat(%q) failed", link)
148                         continue
149                 }
150                 if fi.Sys().(*syscall.Stat_t).Ino == ino {
151                         return uuid + fsPath
152                 }
153         }
154         return giveup("could not find entry in %q matching %q", udir, dev)
155 }
156
157 // Touch sets the timestamp for the given locator to the current time
158 func (v *UnixVolume) Touch(loc string) error {
159         if v.volume.ReadOnly {
160                 return MethodDisabledError
161         }
162         p := v.blockPath(loc)
163         f, err := v.os.OpenFile(p, os.O_RDWR|os.O_APPEND, 0644)
164         if err != nil {
165                 return err
166         }
167         defer f.Close()
168         if err := v.lock(context.TODO()); err != nil {
169                 return err
170         }
171         defer v.unlock()
172         if e := v.lockfile(f); e != nil {
173                 return e
174         }
175         defer v.unlockfile(f)
176         ts := time.Now()
177         v.os.stats.TickOps("utimes")
178         v.os.stats.Tick(&v.os.stats.UtimesOps)
179         err = os.Chtimes(p, ts, ts)
180         v.os.stats.TickErr(err)
181         return err
182 }
183
184 // Mtime returns the stored timestamp for the given locator.
185 func (v *UnixVolume) Mtime(loc string) (time.Time, error) {
186         p := v.blockPath(loc)
187         fi, err := v.os.Stat(p)
188         if err != nil {
189                 return time.Time{}, err
190         }
191         return fi.ModTime(), nil
192 }
193
194 // Lock the locker (if one is in use), open the file for reading, and
195 // call the given function if and when the file is ready to read.
196 func (v *UnixVolume) getFunc(ctx context.Context, path string, fn func(io.Reader) error) error {
197         if err := v.lock(ctx); err != nil {
198                 return err
199         }
200         defer v.unlock()
201         f, err := v.os.Open(path)
202         if err != nil {
203                 return err
204         }
205         defer f.Close()
206         return fn(NewCountingReader(ioutil.NopCloser(f), v.os.stats.TickInBytes))
207 }
208
209 // stat is os.Stat() with some extra sanity checks.
210 func (v *UnixVolume) stat(path string) (os.FileInfo, error) {
211         stat, err := v.os.Stat(path)
212         if err == nil {
213                 if stat.Size() < 0 {
214                         err = os.ErrInvalid
215                 } else if stat.Size() > BlockSize {
216                         err = TooLongError
217                 }
218         }
219         return stat, err
220 }
221
222 // Get retrieves a block, copies it to the given slice, and returns
223 // the number of bytes copied.
224 func (v *UnixVolume) Get(ctx context.Context, loc string, buf []byte) (int, error) {
225         return getWithPipe(ctx, loc, buf, v)
226 }
227
228 // ReadBlock implements BlockReader.
229 func (v *UnixVolume) ReadBlock(ctx context.Context, loc string, w io.Writer) error {
230         path := v.blockPath(loc)
231         stat, err := v.stat(path)
232         if err != nil {
233                 return v.translateError(err)
234         }
235         return v.getFunc(ctx, path, func(rdr io.Reader) error {
236                 n, err := io.Copy(w, rdr)
237                 if err == nil && n != stat.Size() {
238                         err = io.ErrUnexpectedEOF
239                 }
240                 return err
241         })
242 }
243
244 // Compare returns nil if Get(loc) would return the same content as
245 // expect. It is functionally equivalent to Get() followed by
246 // bytes.Compare(), but uses less memory.
247 func (v *UnixVolume) Compare(ctx context.Context, loc string, expect []byte) error {
248         path := v.blockPath(loc)
249         if _, err := v.stat(path); err != nil {
250                 return v.translateError(err)
251         }
252         return v.getFunc(ctx, path, func(rdr io.Reader) error {
253                 return compareReaderWithBuf(ctx, rdr, expect, loc[:32])
254         })
255 }
256
257 // Put stores a block of data identified by the locator string
258 // "loc".  It returns nil on success.  If the volume is full, it
259 // returns a FullError.  If the write fails due to some other error,
260 // that error is returned.
261 func (v *UnixVolume) Put(ctx context.Context, loc string, block []byte) error {
262         return putWithPipe(ctx, loc, block, v)
263 }
264
265 // WriteBlock implements BlockWriter.
266 func (v *UnixVolume) WriteBlock(ctx context.Context, loc string, rdr io.Reader) error {
267         if v.volume.ReadOnly {
268                 return MethodDisabledError
269         }
270         if v.IsFull() {
271                 return FullError
272         }
273         bdir := v.blockDir(loc)
274         if err := os.MkdirAll(bdir, 0755); err != nil {
275                 return fmt.Errorf("error creating directory %s: %s", bdir, err)
276         }
277
278         bpath := v.blockPath(loc)
279         tmpfile, err := v.os.TempFile(bdir, "tmp"+loc)
280         if err != nil {
281                 return fmt.Errorf("TempFile(%s, tmp%s) failed: %s", bdir, loc, err)
282         }
283         defer v.os.Remove(tmpfile.Name())
284         defer tmpfile.Close()
285
286         if err = v.lock(ctx); err != nil {
287                 return err
288         }
289         defer v.unlock()
290         n, err := io.Copy(tmpfile, rdr)
291         v.os.stats.TickOutBytes(uint64(n))
292         if err != nil {
293                 return fmt.Errorf("error writing %s: %s", bpath, err)
294         }
295         if err = tmpfile.Close(); err != nil {
296                 return fmt.Errorf("error closing %s: %s", tmpfile.Name(), err)
297         }
298         // ext4 uses a low-precision clock and effectively backdates
299         // files by up to 10 ms, sometimes across a 1-second boundary,
300         // which produces confusing results in logs and tests.  We
301         // avoid this by setting the output file's timestamps
302         // explicitly, using a higher resolution clock.
303         ts := time.Now()
304         v.os.stats.TickOps("utimes")
305         v.os.stats.Tick(&v.os.stats.UtimesOps)
306         if err = os.Chtimes(tmpfile.Name(), ts, ts); err != nil {
307                 return fmt.Errorf("error setting timestamps on %s: %s", tmpfile.Name(), err)
308         }
309         if err = v.os.Rename(tmpfile.Name(), bpath); err != nil {
310                 return fmt.Errorf("error renaming %s to %s: %s", tmpfile.Name(), bpath, err)
311         }
312         return nil
313 }
314
315 // Status returns a VolumeStatus struct describing the volume's
316 // current state, or nil if an error occurs.
317 func (v *UnixVolume) Status() *VolumeStatus {
318         fi, err := v.os.Stat(v.Root)
319         if err != nil {
320                 v.logger.WithError(err).Error("stat failed")
321                 return nil
322         }
323         // uint64() cast here supports GOOS=darwin where Dev is
324         // int32. If the device number is negative, the unsigned
325         // devnum won't be the real device number any more, but that's
326         // fine -- all we care about is getting the same number each
327         // time.
328         devnum := uint64(fi.Sys().(*syscall.Stat_t).Dev)
329
330         var fs syscall.Statfs_t
331         if err := syscall.Statfs(v.Root, &fs); err != nil {
332                 v.logger.WithError(err).Error("statfs failed")
333                 return nil
334         }
335         // These calculations match the way df calculates disk usage:
336         // "free" space is measured by fs.Bavail, but "used" space
337         // uses fs.Blocks - fs.Bfree.
338         free := fs.Bavail * uint64(fs.Bsize)
339         used := (fs.Blocks - fs.Bfree) * uint64(fs.Bsize)
340         return &VolumeStatus{
341                 MountPoint: v.Root,
342                 DeviceNum:  devnum,
343                 BytesFree:  free,
344                 BytesUsed:  used,
345         }
346 }
347
348 var blockDirRe = regexp.MustCompile(`^[0-9a-f]+$`)
349 var blockFileRe = regexp.MustCompile(`^[0-9a-f]{32}$`)
350
351 // IndexTo writes (to the given Writer) a list of blocks found on this
352 // volume which begin with the specified prefix. If the prefix is an
353 // empty string, IndexTo writes a complete list of blocks.
354 //
355 // Each block is given in the format
356 //
357 //      locator+size modification-time {newline}
358 //
359 // e.g.:
360 //
361 //      e4df392f86be161ca6ed3773a962b8f3+67108864 1388894303
362 //      e4d41e6fd68460e0e3fc18cc746959d2+67108864 1377796043
363 //      e4de7a2810f5554cd39b36d8ddb132ff+67108864 1388701136
364 func (v *UnixVolume) IndexTo(prefix string, w io.Writer) error {
365         rootdir, err := v.os.Open(v.Root)
366         if err != nil {
367                 return err
368         }
369         v.os.stats.TickOps("readdir")
370         v.os.stats.Tick(&v.os.stats.ReaddirOps)
371         subdirs, err := rootdir.Readdirnames(-1)
372         rootdir.Close()
373         if err != nil {
374                 return err
375         }
376         for _, subdir := range subdirs {
377                 if !strings.HasPrefix(subdir, prefix) && !strings.HasPrefix(prefix, subdir) {
378                         // prefix excludes all blocks stored in this dir
379                         continue
380                 }
381                 if !blockDirRe.MatchString(subdir) {
382                         continue
383                 }
384                 blockdirpath := filepath.Join(v.Root, subdir)
385
386                 var dirents []os.DirEntry
387                 for attempt := 0; ; attempt++ {
388                         v.os.stats.TickOps("readdir")
389                         v.os.stats.Tick(&v.os.stats.ReaddirOps)
390                         dirents, err = os.ReadDir(blockdirpath)
391                         if err == nil {
392                                 break
393                         } else if attempt < 5 && strings.Contains(err.Error(), "errno 523") {
394                                 // EBADCOOKIE (NFS stopped accepting
395                                 // our readdirent cookie) -- retry a
396                                 // few times before giving up
397                                 v.logger.WithError(err).Printf("retry after error reading %s", blockdirpath)
398                                 continue
399                         } else {
400                                 return err
401                         }
402                 }
403
404                 for _, dirent := range dirents {
405                         fileInfo, err := dirent.Info()
406                         if os.IsNotExist(err) {
407                                 // File disappeared between ReadDir() and now
408                                 continue
409                         } else if err != nil {
410                                 v.logger.WithError(err).Errorf("error getting FileInfo for %q in %q", dirent.Name(), blockdirpath)
411                                 return err
412                         }
413                         name := fileInfo.Name()
414                         if !strings.HasPrefix(name, prefix) {
415                                 continue
416                         }
417                         if !blockFileRe.MatchString(name) {
418                                 continue
419                         }
420                         _, err = fmt.Fprint(w,
421                                 name,
422                                 "+", fileInfo.Size(),
423                                 " ", fileInfo.ModTime().UnixNano(),
424                                 "\n")
425                         if err != nil {
426                                 return fmt.Errorf("error writing: %s", err)
427                         }
428                 }
429         }
430         return nil
431 }
432
433 // Trash trashes the block data from the unix storage
434 // If BlobTrashLifetime == 0, the block is deleted
435 // Else, the block is renamed as path/{loc}.trash.{deadline},
436 // where deadline = now + BlobTrashLifetime
437 func (v *UnixVolume) Trash(loc string) error {
438         // Touch() must be called before calling Write() on a block.  Touch()
439         // also uses lockfile().  This avoids a race condition between Write()
440         // and Trash() because either (a) the file will be trashed and Touch()
441         // will signal to the caller that the file is not present (and needs to
442         // be re-written), or (b) Touch() will update the file's timestamp and
443         // Trash() will read the correct up-to-date timestamp and choose not to
444         // trash the file.
445
446         if v.volume.ReadOnly || !v.cluster.Collections.BlobTrash {
447                 return MethodDisabledError
448         }
449         if err := v.lock(context.TODO()); err != nil {
450                 return err
451         }
452         defer v.unlock()
453         p := v.blockPath(loc)
454         f, err := v.os.OpenFile(p, os.O_RDWR|os.O_APPEND, 0644)
455         if err != nil {
456                 return err
457         }
458         defer f.Close()
459         if e := v.lockfile(f); e != nil {
460                 return e
461         }
462         defer v.unlockfile(f)
463
464         // If the block has been PUT in the last blobSignatureTTL
465         // seconds, return success without removing the block. This
466         // protects data from garbage collection until it is no longer
467         // possible for clients to retrieve the unreferenced blocks
468         // anyway (because the permission signatures have expired).
469         if fi, err := v.os.Stat(p); err != nil {
470                 return err
471         } else if time.Since(fi.ModTime()) < v.cluster.Collections.BlobSigningTTL.Duration() {
472                 return nil
473         }
474
475         if v.cluster.Collections.BlobTrashLifetime == 0 {
476                 return v.os.Remove(p)
477         }
478         return v.os.Rename(p, fmt.Sprintf("%v.trash.%d", p, time.Now().Add(v.cluster.Collections.BlobTrashLifetime.Duration()).Unix()))
479 }
480
481 // Untrash moves block from trash back into store
482 // Look for path/{loc}.trash.{deadline} in storage,
483 // and rename the first such file as path/{loc}
484 func (v *UnixVolume) Untrash(loc string) (err error) {
485         if v.volume.ReadOnly {
486                 return MethodDisabledError
487         }
488
489         v.os.stats.TickOps("readdir")
490         v.os.stats.Tick(&v.os.stats.ReaddirOps)
491         files, err := ioutil.ReadDir(v.blockDir(loc))
492         if err != nil {
493                 return err
494         }
495
496         if len(files) == 0 {
497                 return os.ErrNotExist
498         }
499
500         foundTrash := false
501         prefix := fmt.Sprintf("%v.trash.", loc)
502         for _, f := range files {
503                 if strings.HasPrefix(f.Name(), prefix) {
504                         foundTrash = true
505                         err = v.os.Rename(v.blockPath(f.Name()), v.blockPath(loc))
506                         if err == nil {
507                                 break
508                         }
509                 }
510         }
511
512         if foundTrash == false {
513                 return os.ErrNotExist
514         }
515
516         return
517 }
518
519 // blockDir returns the fully qualified directory name for the directory
520 // where loc is (or would be) stored on this volume.
521 func (v *UnixVolume) blockDir(loc string) string {
522         return filepath.Join(v.Root, loc[0:3])
523 }
524
525 // blockPath returns the fully qualified pathname for the path to loc
526 // on this volume.
527 func (v *UnixVolume) blockPath(loc string) string {
528         return filepath.Join(v.blockDir(loc), loc)
529 }
530
531 // IsFull returns true if the free space on the volume is less than
532 // MinFreeKilobytes.
533 func (v *UnixVolume) IsFull() (isFull bool) {
534         fullSymlink := v.Root + "/full"
535
536         // Check if the volume has been marked as full in the last hour.
537         if link, err := os.Readlink(fullSymlink); err == nil {
538                 if ts, err := strconv.Atoi(link); err == nil {
539                         fulltime := time.Unix(int64(ts), 0)
540                         if time.Since(fulltime).Hours() < 1.0 {
541                                 return true
542                         }
543                 }
544         }
545
546         if avail, err := v.FreeDiskSpace(); err == nil {
547                 isFull = avail < MinFreeKilobytes
548         } else {
549                 v.logger.WithError(err).Errorf("%s: FreeDiskSpace failed", v)
550                 isFull = false
551         }
552
553         // If the volume is full, timestamp it.
554         if isFull {
555                 now := fmt.Sprintf("%d", time.Now().Unix())
556                 os.Symlink(now, fullSymlink)
557         }
558         return
559 }
560
561 // FreeDiskSpace returns the number of unused 1k blocks available on
562 // the volume.
563 func (v *UnixVolume) FreeDiskSpace() (free uint64, err error) {
564         var fs syscall.Statfs_t
565         err = syscall.Statfs(v.Root, &fs)
566         if err == nil {
567                 // Statfs output is not guaranteed to measure free
568                 // space in terms of 1K blocks.
569                 free = fs.Bavail * uint64(fs.Bsize) / 1024
570         }
571         return
572 }
573
574 func (v *UnixVolume) String() string {
575         return fmt.Sprintf("[UnixVolume %s]", v.Root)
576 }
577
578 // InternalStats returns I/O and filesystem ops counters.
579 func (v *UnixVolume) InternalStats() interface{} {
580         return &v.os.stats
581 }
582
583 // lock acquires the serialize lock, if one is in use. If ctx is done
584 // before the lock is acquired, lock returns ctx.Err() instead of
585 // acquiring the lock.
586 func (v *UnixVolume) lock(ctx context.Context) error {
587         if v.locker == nil {
588                 return nil
589         }
590         t0 := time.Now()
591         locked := make(chan struct{})
592         go func() {
593                 v.locker.Lock()
594                 close(locked)
595         }()
596         select {
597         case <-ctx.Done():
598                 v.logger.Infof("client hung up while waiting for Serialize lock (%s)", time.Since(t0))
599                 go func() {
600                         <-locked
601                         v.locker.Unlock()
602                 }()
603                 return ctx.Err()
604         case <-locked:
605                 return nil
606         }
607 }
608
609 // unlock releases the serialize lock, if one is in use.
610 func (v *UnixVolume) unlock() {
611         if v.locker == nil {
612                 return
613         }
614         v.locker.Unlock()
615 }
616
617 // lockfile and unlockfile use flock(2) to manage kernel file locks.
618 func (v *UnixVolume) lockfile(f *os.File) error {
619         v.os.stats.TickOps("flock")
620         v.os.stats.Tick(&v.os.stats.FlockOps)
621         err := syscall.Flock(int(f.Fd()), syscall.LOCK_EX)
622         v.os.stats.TickErr(err)
623         return err
624 }
625
626 func (v *UnixVolume) unlockfile(f *os.File) error {
627         err := syscall.Flock(int(f.Fd()), syscall.LOCK_UN)
628         v.os.stats.TickErr(err)
629         return err
630 }
631
632 // Where appropriate, translate a more specific filesystem error to an
633 // error recognized by handlers, like os.ErrNotExist.
634 func (v *UnixVolume) translateError(err error) error {
635         switch err.(type) {
636         case *os.PathError:
637                 // stat() returns a PathError if the parent directory
638                 // (not just the file itself) is missing
639                 return os.ErrNotExist
640         default:
641                 return err
642         }
643 }
644
645 var unixTrashLocRegexp = regexp.MustCompile(`/([0-9a-f]{32})\.trash\.(\d+)$`)
646
647 // EmptyTrash walks hierarchy looking for {hash}.trash.*
648 // and deletes those with deadline < now.
649 func (v *UnixVolume) EmptyTrash() {
650         if v.cluster.Collections.BlobDeleteConcurrency < 1 {
651                 return
652         }
653
654         var bytesDeleted, bytesInTrash int64
655         var blocksDeleted, blocksInTrash int64
656
657         doFile := func(path string, info os.FileInfo) {
658                 if info.Mode().IsDir() {
659                         return
660                 }
661                 matches := unixTrashLocRegexp.FindStringSubmatch(path)
662                 if len(matches) != 3 {
663                         return
664                 }
665                 deadline, err := strconv.ParseInt(matches[2], 10, 64)
666                 if err != nil {
667                         v.logger.WithError(err).Errorf("EmptyTrash: %v: ParseInt(%q) failed", path, matches[2])
668                         return
669                 }
670                 atomic.AddInt64(&bytesInTrash, info.Size())
671                 atomic.AddInt64(&blocksInTrash, 1)
672                 if deadline > time.Now().Unix() {
673                         return
674                 }
675                 err = v.os.Remove(path)
676                 if err != nil {
677                         v.logger.WithError(err).Errorf("EmptyTrash: Remove(%q) failed", path)
678                         return
679                 }
680                 atomic.AddInt64(&bytesDeleted, info.Size())
681                 atomic.AddInt64(&blocksDeleted, 1)
682         }
683
684         type dirent struct {
685                 path string
686                 info os.FileInfo
687         }
688         var wg sync.WaitGroup
689         todo := make(chan dirent, v.cluster.Collections.BlobDeleteConcurrency)
690         for i := 0; i < v.cluster.Collections.BlobDeleteConcurrency; i++ {
691                 wg.Add(1)
692                 go func() {
693                         defer wg.Done()
694                         for e := range todo {
695                                 doFile(e.path, e.info)
696                         }
697                 }()
698         }
699
700         err := filepath.Walk(v.Root, func(path string, info os.FileInfo, err error) error {
701                 if err != nil {
702                         v.logger.WithError(err).Errorf("EmptyTrash: filepath.Walk(%q) failed", path)
703                         // Don't give up -- keep walking other
704                         // files/dirs
705                         return nil
706                 } else if !info.Mode().IsDir() {
707                         todo <- dirent{path, info}
708                         return nil
709                 } else if path == v.Root || blockDirRe.MatchString(info.Name()) {
710                         // Descend into a directory that we might have
711                         // put trash in.
712                         return nil
713                 } else {
714                         // Don't descend into other dirs.
715                         return filepath.SkipDir
716                 }
717         })
718         close(todo)
719         wg.Wait()
720
721         if err != nil {
722                 v.logger.WithError(err).Error("EmptyTrash failed")
723         }
724
725         v.logger.Infof("EmptyTrash stats: Deleted %v bytes in %v blocks. Remaining in trash: %v bytes in %v blocks.", bytesDeleted, blocksDeleted, bytesInTrash-bytesDeleted, blocksInTrash-blocksDeleted)
726 }
727
728 type unixStats struct {
729         statsTicker
730         OpenOps    uint64
731         StatOps    uint64
732         FlockOps   uint64
733         UtimesOps  uint64
734         CreateOps  uint64
735         RenameOps  uint64
736         UnlinkOps  uint64
737         ReaddirOps uint64
738 }
739
740 func (s *unixStats) TickErr(err error) {
741         if err == nil {
742                 return
743         }
744         s.statsTicker.TickErr(err, fmt.Sprintf("%T", err))
745 }
746
747 type osWithStats struct {
748         stats unixStats
749 }
750
751 func (o *osWithStats) Open(name string) (*os.File, error) {
752         o.stats.TickOps("open")
753         o.stats.Tick(&o.stats.OpenOps)
754         f, err := os.Open(name)
755         o.stats.TickErr(err)
756         return f, err
757 }
758
759 func (o *osWithStats) OpenFile(name string, flag int, perm os.FileMode) (*os.File, error) {
760         o.stats.TickOps("open")
761         o.stats.Tick(&o.stats.OpenOps)
762         f, err := os.OpenFile(name, flag, perm)
763         o.stats.TickErr(err)
764         return f, err
765 }
766
767 func (o *osWithStats) Remove(path string) error {
768         o.stats.TickOps("unlink")
769         o.stats.Tick(&o.stats.UnlinkOps)
770         err := os.Remove(path)
771         o.stats.TickErr(err)
772         return err
773 }
774
775 func (o *osWithStats) Rename(a, b string) error {
776         o.stats.TickOps("rename")
777         o.stats.Tick(&o.stats.RenameOps)
778         err := os.Rename(a, b)
779         o.stats.TickErr(err)
780         return err
781 }
782
783 func (o *osWithStats) Stat(path string) (os.FileInfo, error) {
784         o.stats.TickOps("stat")
785         o.stats.Tick(&o.stats.StatOps)
786         fi, err := os.Stat(path)
787         o.stats.TickErr(err)
788         return fi, err
789 }
790
791 func (o *osWithStats) TempFile(dir, base string) (*os.File, error) {
792         o.stats.TickOps("create")
793         o.stats.Tick(&o.stats.CreateOps)
794         f, err := ioutil.TempFile(dir, base)
795         o.stats.TickErr(err)
796         return f, err
797 }