Add granular file tracing.

R=thestig@chromium.org,nduca@chromium.org
BUG=480665

Review URL: https://codereview.chromium.org/1072133006

Cr-Commit-Position: refs/heads/master@{#329114}


CrOS-Libchrome-Original-Commit: 492dc31b433656444c9c74213a133c19c8ebfa21
diff --git a/base/files/file.cc b/base/files/file.cc
index 8030bf1..58f80c5 100644
--- a/base/files/file.cc
+++ b/base/files/file.cc
@@ -4,6 +4,7 @@
 
 #include "base/files/file.h"
 #include "base/files/file_path.h"
+#include "base/files/file_tracing.h"
 #include "base/metrics/histogram.h"
 #include "base/timer/elapsed_timer.h"
 
@@ -25,11 +26,11 @@
 }
 
 #if !defined(OS_NACL)
-File::File(const FilePath& name, uint32 flags)
+File::File(const FilePath& path, uint32 flags)
     : error_details_(FILE_OK),
       created_(false),
       async_(false) {
-  Initialize(name, flags);
+  Initialize(path, flags);
 }
 #endif
 
@@ -51,6 +52,7 @@
 
 File::File(RValue other)
     : file_(other.object->TakePlatformFile()),
+      path_(other.object->path_),
       error_details_(other.object->error_details()),
       created_(other.object->created()),
       async_(other.object->async_) {
@@ -65,6 +67,7 @@
   if (this != other.object) {
     Close();
     SetPlatformFile(other.object->TakePlatformFile());
+    path_ = other.object->path_;
     error_details_ = other.object->error_details();
     created_ = other.object->created();
     async_ = other.object->async_;
@@ -73,12 +76,14 @@
 }
 
 #if !defined(OS_NACL)
-void File::Initialize(const FilePath& name, uint32 flags) {
-  if (name.ReferencesParent()) {
+void File::Initialize(const FilePath& path, uint32 flags) {
+  if (path.ReferencesParent()) {
     error_details_ = FILE_ERROR_ACCESS_DENIED;
     return;
   }
-  DoInitialize(name, flags);
+  path_ = path;
+  SCOPED_FILE_TRACE("Initialize");
+  DoInitialize(flags);
 }
 #endif
 
@@ -128,6 +133,7 @@
 
 bool File::Flush() {
   ElapsedTimer timer;
+  SCOPED_FILE_TRACE("Flush");
   bool return_value = DoFlush();
   UMA_HISTOGRAM_TIMES("PlatformFile.FlushTime", timer.Elapsed());
   return return_value;
diff --git a/base/files/file.h b/base/files/file.h
index 89077b4..b21b159 100644
--- a/base/files/file.h
+++ b/base/files/file.h
@@ -18,6 +18,8 @@
 
 #include "base/base_export.h"
 #include "base/basictypes.h"
+#include "base/files/file_path.h"
+#include "base/files/file_tracing.h"
 #include "base/files/scoped_file.h"
 #include "base/gtest_prod_util.h"
 #include "base/move.h"
@@ -31,8 +33,6 @@
 
 namespace base {
 
-class FilePath;
-
 #if defined(OS_WIN)
 typedef HANDLE PlatformFile;
 #elif defined(OS_POSIX)
@@ -162,8 +162,8 @@
   File();
 
   // Creates or opens the given file. This will fail with 'access denied' if the
-  // |name| contains path traversal ('..') components.
-  File(const FilePath& name, uint32 flags);
+  // |path| contains path traversal ('..') components.
+  File(const FilePath& path, uint32 flags);
 
   // Takes ownership of |platform_file|.
   explicit File(PlatformFile platform_file);
@@ -180,7 +180,7 @@
   File& operator=(RValue other);
 
   // Creates or opens the given file.
-  void Initialize(const FilePath& name, uint32 flags);
+  void Initialize(const FilePath& path, uint32 flags);
 
   bool IsValid() const;
 
@@ -191,7 +191,7 @@
 
   // Returns the OS result of opening this file. Note that the way to verify
   // the success of the operation is to use IsValid(), not this method:
-  //   File file(name, flags);
+  //   File file(path, flags);
   //   if (!file.IsValid())
   //     return;
   Error error_details() const { return error_details_; }
@@ -305,6 +305,8 @@
  private:
   FRIEND_TEST_ALL_PREFIXES(::FileTest, MemoryCorruption);
 
+  friend class FileTracing::ScopedTrace;
+
 #if defined(OS_POSIX)
   // Encloses a single ScopedFD, saving a cheap tamper resistent memory checksum
   // alongside it. This checksum is validated at every access, allowing early
@@ -350,9 +352,9 @@
   };
 #endif
 
-  // Creates or opens the given file. Only called if |name| has no traversal
-  // ('..') components.
-  void DoInitialize(const FilePath& name, uint32 flags);
+  // Creates or opens the given file. Only called if |path_| has no
+  // traversal ('..') components.
+  void DoInitialize(uint32 flags);
 
   // TODO(tnagel): Reintegrate into Flush() once histogram isn't needed anymore,
   // cf. issue 473337.
@@ -366,6 +368,12 @@
   MemoryCheckingScopedFD file_;
 #endif
 
+  // Path that |Initialize()| was called with. Only set if safe (i.e. no '..').
+  FilePath path_;
+
+  // Object tied to the lifetime of |this| that enables/disables tracing.
+  FileTracing::ScopedEnabler trace_enabler_;
+
   Error error_details_;
   bool created_;
   bool async_;
diff --git a/base/files/file_posix.cc b/base/files/file_posix.cc
index 4c79057..bb49d2d 100644
--- a/base/files/file_posix.cc
+++ b/base/files/file_posix.cc
@@ -9,7 +9,6 @@
 #include <sys/stat.h>
 #include <unistd.h>
 
-#include "base/files/file_path.h"
 #include "base/logging.h"
 #include "base/metrics/sparse_histogram.h"
 #include "base/posix/eintr_wrapper.h"
@@ -173,6 +172,7 @@
   if (!IsValid())
     return;
 
+  SCOPED_FILE_TRACE("Close");
   ThreadRestrictions::AssertIOAllowed();
   file_.reset();
 }
@@ -181,6 +181,8 @@
   ThreadRestrictions::AssertIOAllowed();
   DCHECK(IsValid());
 
+  SCOPED_FILE_TRACE_WITH_SIZE("Seek", offset);
+
 #if defined(OS_ANDROID)
   COMPILE_ASSERT(sizeof(int64) == sizeof(off64_t), off64_t_64_bit);
   return lseek64(file_.get(), static_cast<off64_t>(offset),
@@ -198,6 +200,8 @@
   if (size < 0)
     return -1;
 
+  SCOPED_FILE_TRACE_WITH_SIZE("Read", size);
+
   int bytes_read = 0;
   int rv;
   do {
@@ -218,6 +222,8 @@
   if (size < 0)
     return -1;
 
+  SCOPED_FILE_TRACE_WITH_SIZE("ReadAtCurrentPos", size);
+
   int bytes_read = 0;
   int rv;
   do {
@@ -234,7 +240,7 @@
 int File::ReadNoBestEffort(int64 offset, char* data, int size) {
   ThreadRestrictions::AssertIOAllowed();
   DCHECK(IsValid());
-
+  SCOPED_FILE_TRACE_WITH_SIZE("ReadNoBestEffort", size);
   return HANDLE_EINTR(pread(file_.get(), data, size, offset));
 }
 
@@ -244,6 +250,7 @@
   if (size < 0)
     return -1;
 
+  SCOPED_FILE_TRACE_WITH_SIZE("ReadAtCurrentPosNoBestEffort", size);
   return HANDLE_EINTR(read(file_.get(), data, size));
 }
 
@@ -257,6 +264,8 @@
   if (size < 0)
     return -1;
 
+  SCOPED_FILE_TRACE_WITH_SIZE("Write", size);
+
   int bytes_written = 0;
   int rv;
   do {
@@ -277,6 +286,8 @@
   if (size < 0)
     return -1;
 
+  SCOPED_FILE_TRACE_WITH_SIZE("WriteAtCurrentPos", size);
+
   int bytes_written = 0;
   int rv;
   do {
@@ -297,12 +308,15 @@
   if (size < 0)
     return -1;
 
+  SCOPED_FILE_TRACE_WITH_SIZE("WriteAtCurrentPosNoBestEffort", size);
   return HANDLE_EINTR(write(file_.get(), data, size));
 }
 
 int64 File::GetLength() {
   DCHECK(IsValid());
 
+  SCOPED_FILE_TRACE("GetLength");
+
   stat_wrapper_t file_info;
   if (CallFstat(file_.get(), &file_info))
     return false;
@@ -313,6 +327,8 @@
 bool File::SetLength(int64 length) {
   ThreadRestrictions::AssertIOAllowed();
   DCHECK(IsValid());
+
+  SCOPED_FILE_TRACE_WITH_SIZE("SetLength", length);
   return !CallFtruncate(file_.get(), length);
 }
 
@@ -320,6 +336,8 @@
   ThreadRestrictions::AssertIOAllowed();
   DCHECK(IsValid());
 
+  SCOPED_FILE_TRACE("SetTimes");
+
   timeval times[2];
   times[0] = last_access_time.ToTimeVal();
   times[1] = last_modified_time.ToTimeVal();
@@ -330,6 +348,8 @@
 bool File::GetInfo(Info* info) {
   DCHECK(IsValid());
 
+  SCOPED_FILE_TRACE("GetInfo");
+
   stat_wrapper_t file_info;
   if (CallFstat(file_.get(), &file_info))
     return false;
@@ -339,10 +359,12 @@
 }
 
 File::Error File::Lock() {
+  SCOPED_FILE_TRACE("Lock");
   return CallFctnlFlock(file_.get(), true);
 }
 
 File::Error File::Unlock() {
+  SCOPED_FILE_TRACE("Unlock");
   return CallFctnlFlock(file_.get(), false);
 }
 
@@ -350,6 +372,8 @@
   if (!IsValid())
     return File();
 
+  SCOPED_FILE_TRACE("Duplicate");
+
   PlatformFile other_fd = dup(GetPlatformFile());
   if (other_fd == -1)
     return File(OSErrorToFileError(errno));
@@ -442,7 +466,7 @@
 // NaCl doesn't implement system calls to open files directly.
 #if !defined(OS_NACL)
 // TODO(erikkay): does it make sense to support FLAG_EXCLUSIVE_* here?
-void File::DoInitialize(const FilePath& name, uint32 flags) {
+void File::DoInitialize(uint32 flags) {
   ThreadRestrictions::AssertIOAllowed();
   DCHECK(!IsValid());
 
@@ -497,7 +521,7 @@
   mode |= S_IRGRP | S_IROTH;
 #endif
 
-  int descriptor = HANDLE_EINTR(open(name.value().c_str(), open_flags, mode));
+  int descriptor = HANDLE_EINTR(open(path_.value().c_str(), open_flags, mode));
 
   if (flags & FLAG_OPEN_ALWAYS) {
     if (descriptor < 0) {
@@ -505,7 +529,7 @@
       if (flags & FLAG_EXCLUSIVE_READ || flags & FLAG_EXCLUSIVE_WRITE)
         open_flags |= O_EXCL;   // together with O_CREAT implies O_NOFOLLOW
 
-      descriptor = HANDLE_EINTR(open(name.value().c_str(), open_flags, mode));
+      descriptor = HANDLE_EINTR(open(path_.value().c_str(), open_flags, mode));
       if (descriptor >= 0)
         created_ = true;
     }
@@ -520,7 +544,7 @@
     created_ = true;
 
   if (flags & FLAG_DELETE_ON_CLOSE)
-    unlink(name.value().c_str());
+    unlink(path_.value().c_str());
 
   async_ = ((flags & FLAG_ASYNC) == FLAG_ASYNC);
   error_details_ = FILE_OK;
@@ -531,6 +555,7 @@
 bool File::DoFlush() {
   ThreadRestrictions::AssertIOAllowed();
   DCHECK(IsValid());
+
 #if defined(OS_NACL)
   NOTIMPLEMENTED();  // NaCl doesn't implement fsync.
   return true;
diff --git a/base/files/file_tracing.cc b/base/files/file_tracing.cc
new file mode 100644
index 0000000..a1919c4
--- /dev/null
+++ b/base/files/file_tracing.cc
@@ -0,0 +1,56 @@
+// Copyright 2015 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#include "base/files/file_tracing.h"
+
+#include "base/files/file.h"
+
+namespace base {
+
+namespace {
+FileTracing::Provider* g_provider = nullptr;
+}
+
+// static
+void FileTracing::SetProvider(FileTracing::Provider* provider) {
+  g_provider = provider;
+}
+
+FileTracing::ScopedEnabler::ScopedEnabler() {
+  if (g_provider)
+    g_provider->FileTracingEnable(this);
+}
+
+FileTracing::ScopedEnabler::~ScopedEnabler() {
+  if (g_provider)
+    g_provider->FileTracingDisable(this);
+}
+
+FileTracing::ScopedTrace::ScopedTrace() : initialized_(false) {}
+
+FileTracing::ScopedTrace::~ScopedTrace() {
+  if (initialized_ && g_provider) {
+    g_provider->FileTracingEventEnd(
+        name_, &file_->trace_enabler_, file_->path_, size_);
+  }
+}
+
+bool FileTracing::ScopedTrace::ShouldInitialize() const {
+  return g_provider && g_provider->FileTracingCategoryIsEnabled();
+}
+
+void FileTracing::ScopedTrace::Initialize(
+    const char* name, File* file, int64 size) {
+  file_ = file;
+  name_ = name;
+  size_ = size;
+  initialized_ = true;
+
+  if (g_provider) {
+    g_provider->FileTracingEventBegin(
+        name_, &file_->trace_enabler_, file_->path_, size_);
+  }
+}
+
+}  // namespace base
diff --git a/base/files/file_tracing.h b/base/files/file_tracing.h
new file mode 100644
index 0000000..8452037
--- /dev/null
+++ b/base/files/file_tracing.h
@@ -0,0 +1,95 @@
+// Copyright 2015 The Chromium Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+#ifndef BASE_FILES_FILE_TRACING_H_
+#define BASE_FILES_FILE_TRACING_H_
+
+#include "base/base_export.h"
+#include "base/basictypes.h"
+#include "base/macros.h"
+
+#define FILE_TRACING_PREFIX "File"
+
+#define SCOPED_FILE_TRACE_WITH_SIZE(name, size) \
+    FileTracing::ScopedTrace scoped_file_trace; \
+    if (scoped_file_trace.ShouldInitialize()) \
+      scoped_file_trace.Initialize(FILE_TRACING_PREFIX "::" name, this, size)
+
+#define SCOPED_FILE_TRACE(name) SCOPED_FILE_TRACE_WITH_SIZE(name, 0)
+
+namespace base {
+
+class File;
+class FilePath;
+
+class BASE_EXPORT FileTracing {
+ public:
+  class Provider {
+   public:
+    // Whether the file tracing category is currently enabled.
+    virtual bool FileTracingCategoryIsEnabled() const = 0;
+
+    // Enables file tracing for |id|. Must be called before recording events.
+    virtual void FileTracingEnable(void* id) = 0;
+
+    // Disables file tracing for |id|.
+    virtual void FileTracingDisable(void* id) = 0;
+
+    // Begins an event for |id| with |name|. |path| tells where in the directory
+    // structure the event is happening (and may be blank). |size| is reported
+    // if not 0.
+    virtual void FileTracingEventBegin(
+        const char* name, void* id, const FilePath& path, int64 size) = 0;
+
+    // Ends an event for |id| with |name|. |path| tells where in the directory
+    // structure the event is happening (and may be blank). |size| is reported
+    // if not 0.
+    virtual void FileTracingEventEnd(
+        const char* name, void* id, const FilePath& path, int64 size) = 0;
+  };
+
+  // Sets a global file tracing provider to query categories and record events.
+  static void SetProvider(Provider* provider);
+
+  // Enables file tracing while in scope.
+  class ScopedEnabler {
+   public:
+    ScopedEnabler();
+    ~ScopedEnabler();
+  };
+
+  class ScopedTrace {
+   public:
+    ScopedTrace();
+    ~ScopedTrace();
+
+    // Whether this trace should be initialized or not.
+    bool ShouldInitialize() const;
+
+    // Called only if the tracing category is enabled.
+    void Initialize(const char* event, File* file, int64 size);
+
+   private:
+    // True if |Initialize()| has been called. Don't touch |path_|, |event_|,
+    // or |bytes_| if |initialized_| is false.
+    bool initialized_;
+
+    // The event name to trace (e.g. "Read", "Write"). Prefixed with "File".
+    const char* name_;
+
+    // The file being traced. Must outlive this class.
+    File* file_;
+
+    // The size (in bytes) of this trace. Not reported if 0.
+    int64 size_;
+
+    DISALLOW_COPY_AND_ASSIGN(ScopedTrace);
+  };
+
+  DISALLOW_COPY_AND_ASSIGN(FileTracing);
+};
+
+}  // namespace base
+
+#endif  // BASE_FILES_FILE_TRACING_H_