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"] = newUnixVolume
  32 }
  33
  34 func newUnixVolume(params newVolumeParams) (volume, error) {
  35         v := &unixVolume{
  36                 uuid:       params.UUID,
  37                 cluster:    params.Cluster,
  38                 volume:     params.ConfigVolume,
  39                 logger:     params.Logger,
  40                 metrics:    params.MetricsVecs,
  41                 bufferPool: params.BufferPool,
  42         }
  43         err := json.Unmarshal(params.ConfigVolume.DriverParameters, &v)
  44         if err != nil {
  45                 return nil, err
  46         }
  47         v.logger = v.logger.WithField("Volume", v.DeviceID())
  48         return v, v.check()
  49 }
  50
  51 func (v *unixVolume) check() error {
  52         if v.Root == "" {
  53                 return errors.New("DriverParameters.Root was not provided")
  54         }
  55         if v.Serialize {
  56                 v.locker = &sync.Mutex{}
  57         }
  58         if !strings.HasPrefix(v.Root, "/") {
  59                 return fmt.Errorf("DriverParameters.Root %q does not start with '/'", v.Root)
  60         }
  61
  62         // Set up prometheus metrics
  63         lbls := prometheus.Labels{"device_id": v.DeviceID()}
  64         v.os.stats.opsCounters, v.os.stats.errCounters, v.os.stats.ioBytes = v.metrics.getCounterVecsFor(lbls)
  65
  66         _, err := v.os.Stat(v.Root)
  67         return err
  68 }
  69
  70 // A unixVolume stores and retrieves blocks in a local directory.
  71 type unixVolume struct {
  72         Root      string // path to the volume's root directory
  73         Serialize bool
  74
  75         uuid       string
  76         cluster    *arvados.Cluster
  77         volume     arvados.Volume
  78         logger     logrus.FieldLogger
  79         metrics    *volumeMetricsVecs
  80         bufferPool *bufferPool
  81
  82         // something to lock during IO, typically a sync.Mutex (or nil
  83         // to skip locking)
  84         locker sync.Locker
  85
  86         os osWithStats
  87 }
  88
  89 // DeviceID returns a globally unique ID for the volume's root
  90 // directory, consisting of the filesystem's UUID and the path from
  91 // filesystem root to storage directory, joined by "/". For example,
  92 // the device ID for a local directory "/mnt/xvda1/keep" might be
  93 // "fa0b6166-3b55-4994-bd3f-92f4e00a1bb0/keep".
  94 func (v *unixVolume) DeviceID() string {
  95         giveup := func(f string, args ...interface{}) string {
  96                 v.logger.Infof(f+"; using hostname:path for volume %s", append(args, v.uuid)...)
  97                 host, _ := os.Hostname()
  98                 return host + ":" + v.Root
  99         }
 100         buf, err := exec.Command("findmnt", "--noheadings", "--target", v.Root).CombinedOutput()
 101         if err != nil {
 102                 return giveup("findmnt: %s (%q)", err, buf)
 103         }
 104         findmnt := strings.Fields(string(buf))
 105         if len(findmnt) < 2 {
 106                 return giveup("could not parse findmnt output: %q", buf)
 107         }
 108         fsRoot, dev := findmnt[0], findmnt[1]
 109
 110         absRoot, err := filepath.Abs(v.Root)
 111         if err != nil {
 112                 return giveup("resolving relative path %q: %s", v.Root, err)
 113         }
 114         realRoot, err := filepath.EvalSymlinks(absRoot)
 115         if err != nil {
 116                 return giveup("resolving symlinks in %q: %s", absRoot, err)
 117         }
 118
 119         // Find path from filesystem root to realRoot
 120         var fsPath string
 121         if strings.HasPrefix(realRoot, fsRoot+"/") {
 122                 fsPath = realRoot[len(fsRoot):]
 123         } else if fsRoot == "/" {
 124                 fsPath = realRoot
 125         } else if fsRoot == realRoot {
 126                 fsPath = ""
 127         } else {
 128                 return giveup("findmnt reports mount point %q which is not a prefix of volume root %q", fsRoot, realRoot)
 129         }
 130
 131         if !strings.HasPrefix(dev, "/") {
 132                 return giveup("mount %q device %q is not a path", fsRoot, dev)
 133         }
 134
 135         fi, err := os.Stat(dev)
 136         if err != nil {
 137                 return giveup("stat %q: %s", dev, err)
 138         }
 139         ino := fi.Sys().(*syscall.Stat_t).Ino
 140
 141         // Find a symlink in /dev/disk/by-uuid/ whose target is (i.e.,
 142         // has the same inode as) the mounted device
 143         udir := "/dev/disk/by-uuid"
 144         d, err := os.Open(udir)
 145         if err != nil {
 146                 return giveup("opening %q: %s", udir, err)
 147         }
 148         defer d.Close()
 149         uuids, err := d.Readdirnames(0)
 150         if err != nil {
 151                 return giveup("reading %q: %s", udir, err)
 152         }
 153         for _, uuid := range uuids {
 154                 link := filepath.Join(udir, uuid)
 155                 fi, err = os.Stat(link)
 156                 if err != nil {
 157                         v.logger.WithError(err).Errorf("stat(%q) failed", link)
 158                         continue
 159                 }
 160                 if fi.Sys().(*syscall.Stat_t).Ino == ino {
 161                         return uuid + fsPath
 162                 }
 163         }
 164         return giveup("could not find entry in %q matching %q", udir, dev)
 165 }
 166
 167 // BlockTouch sets the timestamp for the given locator to the current time
 168 func (v *unixVolume) BlockTouch(hash string) error {
 169         p := v.blockPath(hash)
 170         f, err := v.os.OpenFile(p, os.O_RDWR|os.O_APPEND, 0644)
 171         if err != nil {
 172                 return err
 173         }
 174         defer f.Close()
 175         if err := v.lock(context.TODO()); err != nil {
 176                 return err
 177         }
 178         defer v.unlock()
 179         if e := v.lockfile(f); e != nil {
 180                 return e
 181         }
 182         defer v.unlockfile(f)
 183         ts := time.Now()
 184         v.os.stats.TickOps("utimes")
 185         v.os.stats.Tick(&v.os.stats.UtimesOps)
 186         err = os.Chtimes(p, ts, ts)
 187         v.os.stats.TickErr(err)
 188         return err
 189 }
 190
 191 // Mtime returns the stored timestamp for the given locator.
 192 func (v *unixVolume) Mtime(loc string) (time.Time, error) {
 193         p := v.blockPath(loc)
 194         fi, err := v.os.Stat(p)
 195         if err != nil {
 196                 return time.Time{}, err
 197         }
 198         return fi.ModTime(), nil
 199 }
 200
 201 // Lock the locker (if one is in use), open the file for reading, and
 202 // call the given function if and when the file is ready to read.
 203 func (v *unixVolume) getFunc(ctx context.Context, path string, fn func(io.Reader) error) error {
 204         if err := v.lock(ctx); err != nil {
 205                 return err
 206         }
 207         defer v.unlock()
 208         f, err := v.os.Open(path)
 209         if err != nil {
 210                 return err
 211         }
 212         defer f.Close()
 213         return fn(newCountingReader(ioutil.NopCloser(f), v.os.stats.TickInBytes))
 214 }
 215
 216 // stat is os.Stat() with some extra sanity checks.
 217 func (v *unixVolume) stat(path string) (os.FileInfo, error) {
 218         stat, err := v.os.Stat(path)
 219         if err == nil {
 220                 if stat.Size() < 0 {
 221                         err = os.ErrInvalid
 222                 } else if stat.Size() > BlockSize {
 223                         err = errTooLarge
 224                 }
 225         }
 226         return stat, err
 227 }
 228
 229 // BlockRead reads a block from the volume.
 230 func (v *unixVolume) BlockRead(ctx context.Context, hash string, w io.Writer) (int, error) {
 231         path := v.blockPath(hash)
 232         stat, err := v.stat(path)
 233         if err != nil {
 234                 return 0, v.translateError(err)
 235         }
 236         var streamer *streamWriterAt
 237         if v.locker != nil {
 238                 buf, err := v.bufferPool.GetContext(ctx)
 239                 if err != nil {
 240                         return 0, err
 241                 }
 242                 defer v.bufferPool.Put(buf)
 243                 streamer = newStreamWriterAt(w, 65536, buf)
 244                 defer streamer.Close()
 245                 w = streamer
 246         }
 247         var n int64
 248         err = v.getFunc(ctx, path, func(rdr io.Reader) error {
 249                 n, err = io.Copy(w, rdr)
 250                 if err == nil && n != stat.Size() {
 251                         err = io.ErrUnexpectedEOF
 252                 }
 253                 return err
 254         })
 255         if streamer != nil {
 256                 // If we're using the streamer (and there's no error
 257                 // so far) flush any remaining buffered data now that
 258                 // getFunc has released the serialize lock.
 259                 if err == nil {
 260                         err = streamer.Close()
 261                 }
 262                 return streamer.WroteAt(), err
 263         }
 264         return int(n), err
 265 }
 266
 267 // BlockWrite stores a block on the volume. If it already exists, its
 268 // timestamp is updated.
 269 func (v *unixVolume) BlockWrite(ctx context.Context, hash string, data []byte) error {
 270         if v.isFull() {
 271                 return errFull
 272         }
 273         bdir := v.blockDir(hash)
 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(hash)
 279         tmpfile, err := v.os.TempFile(bdir, "tmp"+hash)
 280         if err != nil {
 281                 return fmt.Errorf("TempFile(%s, tmp%s) failed: %s", bdir, hash, 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 := tmpfile.Write(data)
 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 var blockDirRe = regexp.MustCompile(`^[0-9a-f]+$`)
 316 var blockFileRe = regexp.MustCompile(`^[0-9a-f]{32}$`)
 317
 318 func (v *unixVolume) Index(ctx context.Context, prefix string, w io.Writer) error {
 319         rootdir, err := v.os.Open(v.Root)
 320         if err != nil {
 321                 return err
 322         }
 323         v.os.stats.TickOps("readdir")
 324         v.os.stats.Tick(&v.os.stats.ReaddirOps)
 325         subdirs, err := rootdir.Readdirnames(-1)
 326         rootdir.Close()
 327         if err != nil {
 328                 return err
 329         }
 330         for _, subdir := range subdirs {
 331                 if ctx.Err() != nil {
 332                         return ctx.Err()
 333                 }
 334                 if !strings.HasPrefix(subdir, prefix) && !strings.HasPrefix(prefix, subdir) {
 335                         // prefix excludes all blocks stored in this dir
 336                         continue
 337                 }
 338                 if !blockDirRe.MatchString(subdir) {
 339                         continue
 340                 }
 341                 blockdirpath := filepath.Join(v.Root, subdir)
 342
 343                 var dirents []os.DirEntry
 344                 for attempt := 0; ; attempt++ {
 345                         v.os.stats.TickOps("readdir")
 346                         v.os.stats.Tick(&v.os.stats.ReaddirOps)
 347                         dirents, err = os.ReadDir(blockdirpath)
 348                         if ctx.Err() != nil {
 349                                 return ctx.Err()
 350                         } else if err == nil {
 351                                 break
 352                         } else if attempt < 5 && strings.Contains(err.Error(), "errno 523") {
 353                                 // EBADCOOKIE (NFS stopped accepting
 354                                 // our readdirent cookie) -- retry a
 355                                 // few times before giving up
 356                                 v.logger.WithError(err).Printf("retry after error reading %s", blockdirpath)
 357                                 continue
 358                         } else {
 359                                 return err
 360                         }
 361                 }
 362
 363                 for _, dirent := range dirents {
 364                         if ctx.Err() != nil {
 365                                 return ctx.Err()
 366                         }
 367                         fileInfo, err := dirent.Info()
 368                         if os.IsNotExist(err) {
 369                                 // File disappeared between ReadDir() and now
 370                                 continue
 371                         } else if err != nil {
 372                                 v.logger.WithError(err).Errorf("error getting FileInfo for %q in %q", dirent.Name(), blockdirpath)
 373                                 return err
 374                         }
 375                         name := fileInfo.Name()
 376                         if !strings.HasPrefix(name, prefix) {
 377                                 continue
 378                         }
 379                         if !blockFileRe.MatchString(name) {
 380                                 continue
 381                         }
 382                         _, err = fmt.Fprint(w,
 383                                 name,
 384                                 "+", fileInfo.Size(),
 385                                 " ", fileInfo.ModTime().UnixNano(),
 386                                 "\n")
 387                         if err != nil {
 388                                 return fmt.Errorf("error writing: %s", err)
 389                         }
 390                 }
 391         }
 392         return nil
 393 }
 394
 395 // BlockTrash trashes the block data from the unix storage.  If
 396 // BlobTrashLifetime == 0, the block is deleted; otherwise, the block
 397 // is renamed as path/{loc}.trash.{deadline}, where deadline = now +
 398 // BlobTrashLifetime.
 399 func (v *unixVolume) BlockTrash(loc string) error {
 400         // Touch() must be called before calling Write() on a block.  Touch()
 401         // also uses lockfile().  This avoids a race condition between Write()
 402         // and Trash() because either (a) the file will be trashed and Touch()
 403         // will signal to the caller that the file is not present (and needs to
 404         // be re-written), or (b) Touch() will update the file's timestamp and
 405         // Trash() will read the correct up-to-date timestamp and choose not to
 406         // trash the file.
 407         if err := v.lock(context.TODO()); err != nil {
 408                 return err
 409         }
 410         defer v.unlock()
 411         p := v.blockPath(loc)
 412         f, err := v.os.OpenFile(p, os.O_RDWR|os.O_APPEND, 0644)
 413         if err != nil {
 414                 return err
 415         }
 416         defer f.Close()
 417         if e := v.lockfile(f); e != nil {
 418                 return e
 419         }
 420         defer v.unlockfile(f)
 421
 422         // If the block has been PUT in the last blobSignatureTTL
 423         // seconds, return success without removing the block. This
 424         // protects data from garbage collection until it is no longer
 425         // possible for clients to retrieve the unreferenced blocks
 426         // anyway (because the permission signatures have expired).
 427         if fi, err := v.os.Stat(p); err != nil {
 428                 return err
 429         } else if time.Since(fi.ModTime()) < v.cluster.Collections.BlobSigningTTL.Duration() {
 430                 return nil
 431         }
 432
 433         if v.cluster.Collections.BlobTrashLifetime == 0 {
 434                 return v.os.Remove(p)
 435         }
 436         return v.os.Rename(p, fmt.Sprintf("%v.trash.%d", p, time.Now().Add(v.cluster.Collections.BlobTrashLifetime.Duration()).Unix()))
 437 }
 438
 439 // BlockUntrash moves block from trash back into store
 440 // Look for path/{loc}.trash.{deadline} in storage,
 441 // and rename the first such file as path/{loc}
 442 func (v *unixVolume) BlockUntrash(hash string) error {
 443         v.os.stats.TickOps("readdir")
 444         v.os.stats.Tick(&v.os.stats.ReaddirOps)
 445         files, err := ioutil.ReadDir(v.blockDir(hash))
 446         if err != nil {
 447                 return err
 448         }
 449
 450         if len(files) == 0 {
 451                 return os.ErrNotExist
 452         }
 453
 454         foundTrash := false
 455         prefix := fmt.Sprintf("%v.trash.", hash)
 456         for _, f := range files {
 457                 if strings.HasPrefix(f.Name(), prefix) {
 458                         foundTrash = true
 459                         err = v.os.Rename(v.blockPath(f.Name()), v.blockPath(hash))
 460                         if err == nil {
 461                                 break
 462                         }
 463                 }
 464         }
 465
 466         if foundTrash == false {
 467                 return os.ErrNotExist
 468         }
 469
 470         return nil
 471 }
 472
 473 // blockDir returns the fully qualified directory name for the directory
 474 // where loc is (or would be) stored on this volume.
 475 func (v *unixVolume) blockDir(loc string) string {
 476         return filepath.Join(v.Root, loc[0:3])
 477 }
 478
 479 // blockPath returns the fully qualified pathname for the path to loc
 480 // on this volume.
 481 func (v *unixVolume) blockPath(loc string) string {
 482         return filepath.Join(v.blockDir(loc), loc)
 483 }
 484
 485 // isFull returns true if the free space on the volume is less than
 486 // MinFreeKilobytes.
 487 func (v *unixVolume) isFull() (isFull bool) {
 488         fullSymlink := v.Root + "/full"
 489
 490         // Check if the volume has been marked as full in the last hour.
 491         if link, err := os.Readlink(fullSymlink); err == nil {
 492                 if ts, err := strconv.Atoi(link); err == nil {
 493                         fulltime := time.Unix(int64(ts), 0)
 494                         if time.Since(fulltime).Hours() < 1.0 {
 495                                 return true
 496                         }
 497                 }
 498         }
 499
 500         if avail, err := v.FreeDiskSpace(); err == nil {
 501                 isFull = avail < BlockSize
 502         } else {
 503                 v.logger.WithError(err).Errorf("%s: FreeDiskSpace failed", v.DeviceID())
 504                 isFull = false
 505         }
 506
 507         // If the volume is full, timestamp it.
 508         if isFull {
 509                 now := fmt.Sprintf("%d", time.Now().Unix())
 510                 os.Symlink(now, fullSymlink)
 511         }
 512         return
 513 }
 514
 515 // FreeDiskSpace returns the number of unused 1k blocks available on
 516 // the volume.
 517 func (v *unixVolume) FreeDiskSpace() (free uint64, err error) {
 518         var fs syscall.Statfs_t
 519         err = syscall.Statfs(v.Root, &fs)
 520         if err == nil {
 521                 // Statfs output is not guaranteed to measure free
 522                 // space in terms of 1K blocks.
 523                 free = fs.Bavail * uint64(fs.Bsize)
 524         }
 525         return
 526 }
 527
 528 // InternalStats returns I/O and filesystem ops counters.
 529 func (v *unixVolume) InternalStats() interface{} {
 530         return &v.os.stats
 531 }
 532
 533 // lock acquires the serialize lock, if one is in use. If ctx is done
 534 // before the lock is acquired, lock returns ctx.Err() instead of
 535 // acquiring the lock.
 536 func (v *unixVolume) lock(ctx context.Context) error {
 537         if v.locker == nil {
 538                 return nil
 539         }
 540         t0 := time.Now()
 541         locked := make(chan struct{})
 542         go func() {
 543                 v.locker.Lock()
 544                 close(locked)
 545         }()
 546         select {
 547         case <-ctx.Done():
 548                 v.logger.Infof("client hung up while waiting for Serialize lock (%s)", time.Since(t0))
 549                 go func() {
 550                         <-locked
 551                         v.locker.Unlock()
 552                 }()
 553                 return ctx.Err()
 554         case <-locked:
 555                 return nil
 556         }
 557 }
 558
 559 // unlock releases the serialize lock, if one is in use.
 560 func (v *unixVolume) unlock() {
 561         if v.locker == nil {
 562                 return
 563         }
 564         v.locker.Unlock()
 565 }
 566
 567 // lockfile and unlockfile use flock(2) to manage kernel file locks.
 568 func (v *unixVolume) lockfile(f *os.File) error {
 569         v.os.stats.TickOps("flock")
 570         v.os.stats.Tick(&v.os.stats.FlockOps)
 571         err := syscall.Flock(int(f.Fd()), syscall.LOCK_EX)
 572         v.os.stats.TickErr(err)
 573         return err
 574 }
 575
 576 func (v *unixVolume) unlockfile(f *os.File) error {
 577         err := syscall.Flock(int(f.Fd()), syscall.LOCK_UN)
 578         v.os.stats.TickErr(err)
 579         return err
 580 }
 581
 582 // Where appropriate, translate a more specific filesystem error to an
 583 // error recognized by handlers, like os.ErrNotExist.
 584 func (v *unixVolume) translateError(err error) error {
 585         switch err.(type) {
 586         case *os.PathError:
 587                 // stat() returns a PathError if the parent directory
 588                 // (not just the file itself) is missing
 589                 return os.ErrNotExist
 590         default:
 591                 return err
 592         }
 593 }
 594
 595 var unixTrashLocRegexp = regexp.MustCompile(`/([0-9a-f]{32})\.trash\.(\d+)$`)
 596
 597 // EmptyTrash walks hierarchy looking for {hash}.trash.*
 598 // and deletes those with deadline < now.
 599 func (v *unixVolume) EmptyTrash() {
 600         var bytesDeleted, bytesInTrash int64
 601         var blocksDeleted, blocksInTrash int64
 602
 603         doFile := func(path string, info os.FileInfo) {
 604                 if info.Mode().IsDir() {
 605                         return
 606                 }
 607                 matches := unixTrashLocRegexp.FindStringSubmatch(path)
 608                 if len(matches) != 3 {
 609                         return
 610                 }
 611                 deadline, err := strconv.ParseInt(matches[2], 10, 64)
 612                 if err != nil {
 613                         v.logger.WithError(err).Errorf("EmptyTrash: %v: ParseInt(%q) failed", path, matches[2])
 614                         return
 615                 }
 616                 atomic.AddInt64(&bytesInTrash, info.Size())
 617                 atomic.AddInt64(&blocksInTrash, 1)
 618                 if deadline > time.Now().Unix() {
 619                         return
 620                 }
 621                 err = v.os.Remove(path)
 622                 if err != nil {
 623                         v.logger.WithError(err).Errorf("EmptyTrash: Remove(%q) failed", path)
 624                         return
 625                 }
 626                 atomic.AddInt64(&bytesDeleted, info.Size())
 627                 atomic.AddInt64(&blocksDeleted, 1)
 628         }
 629
 630         type dirent struct {
 631                 path string
 632                 info os.FileInfo
 633         }
 634         var wg sync.WaitGroup
 635         todo := make(chan dirent, v.cluster.Collections.BlobDeleteConcurrency)
 636         for i := 0; i < v.cluster.Collections.BlobDeleteConcurrency; i++ {
 637                 wg.Add(1)
 638                 go func() {
 639                         defer wg.Done()
 640                         for e := range todo {
 641                                 doFile(e.path, e.info)
 642                         }
 643                 }()
 644         }
 645
 646         err := filepath.Walk(v.Root, func(path string, info os.FileInfo, err error) error {
 647                 if err != nil {
 648                         v.logger.WithError(err).Errorf("EmptyTrash: filepath.Walk(%q) failed", path)
 649                         // Don't give up -- keep walking other
 650                         // files/dirs
 651                         return nil
 652                 } else if !info.Mode().IsDir() {
 653                         todo <- dirent{path, info}
 654                         return nil
 655                 } else if path == v.Root || blockDirRe.MatchString(info.Name()) {
 656                         // Descend into a directory that we might have
 657                         // put trash in.
 658                         return nil
 659                 } else {
 660                         // Don't descend into other dirs.
 661                         return filepath.SkipDir
 662                 }
 663         })
 664         close(todo)
 665         wg.Wait()
 666
 667         if err != nil {
 668                 v.logger.WithError(err).Error("EmptyTrash failed")
 669         }
 670
 671         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)
 672 }
 673
 674 type unixStats struct {
 675         statsTicker
 676         OpenOps    uint64
 677         StatOps    uint64
 678         FlockOps   uint64
 679         UtimesOps  uint64
 680         CreateOps  uint64
 681         RenameOps  uint64
 682         UnlinkOps  uint64
 683         ReaddirOps uint64
 684 }
 685
 686 func (s *unixStats) TickErr(err error) {
 687         if err == nil {
 688                 return
 689         }
 690         s.statsTicker.TickErr(err, fmt.Sprintf("%T", err))
 691 }
 692
 693 type osWithStats struct {
 694         stats unixStats
 695 }
 696
 697 func (o *osWithStats) Open(name string) (*os.File, error) {
 698         o.stats.TickOps("open")
 699         o.stats.Tick(&o.stats.OpenOps)
 700         f, err := os.Open(name)
 701         o.stats.TickErr(err)
 702         return f, err
 703 }
 704
 705 func (o *osWithStats) OpenFile(name string, flag int, perm os.FileMode) (*os.File, error) {
 706         o.stats.TickOps("open")
 707         o.stats.Tick(&o.stats.OpenOps)
 708         f, err := os.OpenFile(name, flag, perm)
 709         o.stats.TickErr(err)
 710         return f, err
 711 }
 712
 713 func (o *osWithStats) Remove(path string) error {
 714         o.stats.TickOps("unlink")
 715         o.stats.Tick(&o.stats.UnlinkOps)
 716         err := os.Remove(path)
 717         o.stats.TickErr(err)
 718         return err
 719 }
 720
 721 func (o *osWithStats) Rename(a, b string) error {
 722         o.stats.TickOps("rename")
 723         o.stats.Tick(&o.stats.RenameOps)
 724         err := os.Rename(a, b)
 725         o.stats.TickErr(err)
 726         return err
 727 }
 728
 729 func (o *osWithStats) Stat(path string) (os.FileInfo, error) {
 730         o.stats.TickOps("stat")
 731         o.stats.Tick(&o.stats.StatOps)
 732         fi, err := os.Stat(path)
 733         o.stats.TickErr(err)
 734         return fi, err
 735 }
 736
 737 func (o *osWithStats) TempFile(dir, base string) (*os.File, error) {
 738         o.stats.TickOps("create")
 739         o.stats.Tick(&o.stats.CreateOps)
 740         f, err := ioutil.TempFile(dir, base)
 741         o.stats.TickErr(err)
 742         return f, err
 743 }