Record UMA statistics for file_stream operations.

net/base/file_stream_win.cc

 // Copyright (c) 2011 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 "net/base/file_stream.h"
 
 #include <windows.h>
 
 #include "base/file_path.h"
 #include "base/logging.h"
 #include "base/message_loop.h"
 #include "base/metrics/histogram.h"
 #include "base/threading/thread_restrictions.h"
+#include "net/base/file_stream_metrics.h"
 #include "net/base/net_errors.h"
 
 namespace net {
 
 // Ensure that we can just use our Whence values directly.
 COMPILE_ASSERT(FROM_BEGIN == FILE_BEGIN, bad_whence_begin);
 COMPILE_ASSERT(FROM_CURRENT == FILE_CURRENT, bad_whence_current);
 COMPILE_ASSERT(FROM_END == FILE_END, bad_whence_end);
 
 static void SetOffset(OVERLAPPED* overlapped, const LARGE_INTEGER& offset) {
@@ skipping 21 matching lines @@
     default:
       LOG(WARNING) << "Unknown error " << err << " mapped to net::ERR_FAILED";
       return ERR_FAILED;
   }
 }
 
 // FileStream::AsyncContext ----------------------------------------------
 
 class FileStream::AsyncContext : public MessageLoopForIO::IOHandler {
  public:
+  enum AsyncOperation {
+    ASYNC_OPERATION_NONE = 0,
+    ASYNC_OPERATION_READ,
+    ASYNC_OPERATION_WRITE,
+    ASYNC_OPERATION_SEEK,
+  };
+
   AsyncContext(FileStream* owner)
-      : owner_(owner), context_(), callback_(NULL), is_closing_(false) {
+      : owner_(owner), context_(), callback_(NULL), is_closing_(false),
+        record_uma_(false), operation_(ASYNC_OPERATION_NONE) {
     context_.handler = this;
   }
   ~AsyncContext();
 
   void IOCompletionIsPending(CompletionCallback* callback);
 
   OVERLAPPED* overlapped() { return &context_.overlapped; }
   CompletionCallback* callback() const { return callback_; }
 
+  void set_operation(AsyncOperation operation) { operation_ = operation; }

[cbentzel, 2011/08/18 13:31:28]

Why isn't this just FILE_ERROR_SOURCE? That way you don't have to worry about
the new enum and the mapping of that enum to FILE_ERROR_SOURCE, which is all you
care about anyway.

Also - is it possible for there to be multiple operations on the same
AsyncContext? I don't think there is, but just want to double-check. 

[ahendrickson, 2011/08/18 15:56:45]

I believe there is 0 or 1 AsyncContext's per FileStream, depending on how it's
created.  That implies that all operations done on a FileStream (read, write,
seek) can go through the AsyncContext, so multiple operations are possible.

However, I would expect one operation to complete before another one is started.
 What do you think?

Changed operation_ to be a FileErrorSource, and renamed it.

+
+  void EnableErrorStatistics() {
+    record_uma_ = true;
+  }
+
  private:
   virtual void OnIOCompleted(MessageLoopForIO::IOContext* context,
                              DWORD bytes_read, DWORD error);
 
   FileStream* owner_;
   MessageLoopForIO::IOContext context_;
   CompletionCallback* callback_;
   bool is_closing_;
+  bool record_uma_;
+  AsyncOperation operation_;
 };
 
 FileStream::AsyncContext::~AsyncContext() {
   is_closing_ = true;
   bool waited = false;
   base::TimeTicks start = base::TimeTicks::Now();
   while (callback_) {
     waited = true;
     MessageLoopForIO::current()->WaitForIOCompletion(INFINITE, this);
   }
   if (waited) {
     // We want to see if we block the message loop for too long.
     UMA_HISTOGRAM_TIMES("AsyncIO.FileStreamClose",
                         base::TimeTicks::Now() - start);
   }
 }
 
 void FileStream::AsyncContext::IOCompletionIsPending(
     CompletionCallback* callback) {
   DCHECK(!callback_);
   callback_ = callback;
 }
 
 void FileStream::AsyncContext::OnIOCompleted(
     MessageLoopForIO::IOContext* context, DWORD bytes_read, DWORD error) {
   DCHECK_EQ(&context_, context);
   DCHECK(callback_);
 
+  static FileErrorSource source_map[] = {
+    FILE_ERROR_SOURCE_COUNT,  // ASYNC_OPERATION_NONE
+    FILE_ERROR_SOURCE_READ,   // ASYNC_OPERATION_READ
+    FILE_ERROR_SOURCE_WRITE,  // ASYNC_OPERATION_WRITE
+    FILE_ERROR_SOURCE_SEEK,   // ASYNC_OPERATION_SEEK
+  };
+
   if (is_closing_) {
     callback_ = NULL;
     return;
   }
 
   int result = static_cast<int>(bytes_read);
-  if (error && error != ERROR_HANDLE_EOF)
+  if (error && error != ERROR_HANDLE_EOF) {
+    RecordFileError(error, source_map[operation_], record_uma_);
     result = MapErrorCode(error);
+  }
 
   if (bytes_read)
     IncrementOffset(&context->overlapped, bytes_read);
 
   CompletionCallback* temp = NULL;
   std::swap(temp, callback_);
   temp->Run(result);
 }
 
 // FileStream ------------------------------------------------------------
 
 FileStream::FileStream()
     : file_(INVALID_HANDLE_VALUE),
       open_flags_(0),
-      auto_closed_(true) {
+      auto_closed_(true),
+      record_uma_(false) {
 }
 
 FileStream::FileStream(base::PlatformFile file, int flags)
     : file_(file),
       open_flags_(flags),
-      auto_closed_(false) {
+      auto_closed_(false),
+      record_uma_(false) {
   // If the file handle is opened with base::PLATFORM_FILE_ASYNC, we need to
   // make sure we will perform asynchronous File IO to it.
   if (flags & base::PLATFORM_FILE_ASYNC) {
     async_context_.reset(new AsyncContext(this));
     MessageLoopForIO::current()->RegisterIOHandler(file_,
                                                    async_context_.get());
   }
 }
 
 FileStream::~FileStream() {
@@ skipping 16 matching lines @@
   if (IsOpen()) {
     DLOG(FATAL) << "File is already open!";
     return ERR_UNEXPECTED;
   }
 
   open_flags_ = open_flags;
   file_ = base::CreatePlatformFile(path, open_flags_, NULL, NULL);
   if (file_ == INVALID_HANDLE_VALUE) {
     DWORD error = GetLastError();
     LOG(WARNING) << "Failed to open file: " << error;
-    return MapErrorCode(error);
+    return RecordAndMapError(error, FILE_ERROR_SOURCE_OPEN);
   }
 
   if (open_flags_ & base::PLATFORM_FILE_ASYNC) {
     async_context_.reset(new AsyncContext(this));
+    if (record_uma_)
+      async_context_->EnableErrorStatistics();
     MessageLoopForIO::current()->RegisterIOHandler(file_,
                                                    async_context_.get());
   }
 
   return OK;
 }
 
 bool FileStream::IsOpen() const {
   return file_ != INVALID_HANDLE_VALUE;
 }
 
 int64 FileStream::Seek(Whence whence, int64 offset) {
   if (!IsOpen())
     return ERR_UNEXPECTED;
+
   DCHECK(!async_context_.get() || !async_context_->callback());
 
   LARGE_INTEGER distance, result;
   distance.QuadPart = offset;
   DWORD move_method = static_cast<DWORD>(whence);
   if (!SetFilePointerEx(file_, distance, &result, move_method)) {
     DWORD error = GetLastError();
     LOG(WARNING) << "SetFilePointerEx failed: " << error;
-    return MapErrorCode(error);
+    return RecordAndMapError(error, FILE_ERROR_SOURCE_SEEK);
   }
-  if (async_context_.get())
+  if (async_context_.get()) {
+    async_context_->set_operation(AsyncContext::ASYNC_OPERATION_SEEK);
     SetOffset(async_context_->overlapped(), result);
+  }
   return result.QuadPart;
 }
 
 int64 FileStream::Available() {
   base::ThreadRestrictions::AssertIOAllowed();
 
   if (!IsOpen())
     return ERR_UNEXPECTED;
 
   int64 cur_pos = Seek(FROM_CURRENT, 0);
   if (cur_pos < 0)
     return cur_pos;
 
   LARGE_INTEGER file_size;
   if (!GetFileSizeEx(file_, &file_size)) {
     DWORD error = GetLastError();
     LOG(WARNING) << "GetFileSizeEx failed: " << error;
-    return MapErrorCode(error);
+    return RecordAndMapError(error, FILE_ERROR_SOURCE_GET_SIZE);
   }
 
   return file_size.QuadPart - cur_pos;
 }
 
 int FileStream::Read(
     char* buf, int buf_len, CompletionCallback* callback) {
   if (!IsOpen())
     return ERR_UNEXPECTED;
+
   DCHECK(open_flags_ & base::PLATFORM_FILE_READ);
 
   OVERLAPPED* overlapped = NULL;
   if (async_context_.get()) {
     DCHECK(callback);
     DCHECK(!async_context_->callback());
     overlapped = async_context_->overlapped();
+    async_context_->set_operation(AsyncContext::ASYNC_OPERATION_READ);
   } else {
     DCHECK(!callback);
     base::ThreadRestrictions::AssertIOAllowed();
   }
 
   int rv;
 
   DWORD bytes_read;
   if (!ReadFile(file_, buf, buf_len, &bytes_read, overlapped)) {
     DWORD error = GetLastError();
     if (async_context_.get() && error == ERROR_IO_PENDING) {
       async_context_->IOCompletionIsPending(callback);
       rv = ERR_IO_PENDING;
     } else if (error == ERROR_HANDLE_EOF) {
       rv = 0;  // Report EOF by returning 0 bytes read.
     } else {
       LOG(WARNING) << "ReadFile failed: " << error;
-      rv = MapErrorCode(error);
+      rv = RecordAndMapError(error, FILE_ERROR_SOURCE_READ);
     }
   } else if (overlapped) {
     async_context_->IOCompletionIsPending(callback);
     rv = ERR_IO_PENDING;
   } else {
     rv = static_cast<int>(bytes_read);
   }
   return rv;
 }
 
@@ skipping 15 matching lines @@
     to_read -= bytes_read;
   } while (bytes_total < buf_len);
 
   return bytes_total;
 }
 
 int FileStream::Write(
     const char* buf, int buf_len, CompletionCallback* callback) {
   if (!IsOpen())
     return ERR_UNEXPECTED;
+
   DCHECK(open_flags_ & base::PLATFORM_FILE_WRITE);
 
   OVERLAPPED* overlapped = NULL;
   if (async_context_.get()) {
     DCHECK(callback);
     DCHECK(!async_context_->callback());
     overlapped = async_context_->overlapped();
+    async_context_->set_operation(AsyncContext::ASYNC_OPERATION_WRITE);
   } else {
     DCHECK(!callback);
     base::ThreadRestrictions::AssertIOAllowed();
   }
 
   int rv;
   DWORD bytes_written;
   if (!WriteFile(file_, buf, buf_len, &bytes_written, overlapped)) {
     DWORD error = GetLastError();
     if (async_context_.get() && error == ERROR_IO_PENDING) {
       async_context_->IOCompletionIsPending(callback);
       rv = ERR_IO_PENDING;
     } else {
       LOG(WARNING) << "WriteFile failed: " << error;
-      rv = MapErrorCode(error);
+      rv = RecordAndMapError(error, FILE_ERROR_SOURCE_WRITE);
     }
   } else if (overlapped) {
     async_context_->IOCompletionIsPending(callback);
     rv = ERR_IO_PENDING;
   } else {
     rv = static_cast<int>(bytes_written);
   }
   return rv;
 }
 
 int FileStream::Flush() {
   base::ThreadRestrictions::AssertIOAllowed();
 
   if (!IsOpen())
     return ERR_UNEXPECTED;
 
   DCHECK(open_flags_ & base::PLATFORM_FILE_WRITE);
   if (FlushFileBuffers(file_)) {
     return OK;
   }
 
-  int rv;
-  DWORD error = GetLastError();
-  rv = MapErrorCode(error);
-  return rv;
+  return RecordAndMapError(GetLastError(), FILE_ERROR_SOURCE_FLUSH);
 }
 
 int64 FileStream::Truncate(int64 bytes) {
   base::ThreadRestrictions::AssertIOAllowed();
 
   if (!IsOpen())
     return ERR_UNEXPECTED;
 
   // We better be open for reading.
   DCHECK(open_flags_ & base::PLATFORM_FILE_WRITE);
 
   // Seek to the position to truncate from.
   int64 seek_position = Seek(FROM_BEGIN, bytes);
   if (seek_position != bytes)
     return ERR_UNEXPECTED;
 
   // And truncate the file.
   BOOL result = SetEndOfFile(file_);
   if (!result) {
     DWORD error = GetLastError();
     LOG(WARNING) << "SetEndOfFile failed: " << error;
-    return MapErrorCode(error);
+    return RecordAndMapError(error, FILE_ERROR_SOURCE_SET_EOF);
   }
 
   // Success.
   return seek_position;
 }
 
+void FileStream::EnableErrorStatistics() {
+  record_uma_ = true;
+
+  if (async_context_.get())
+    async_context_->EnableErrorStatistics();
+}
+
+int FileStream::RecordAndMapError(int error, FileErrorSource source) {
+  RecordFileError(error, source, record_uma_);
+  return MapErrorCode(error);
+}
+
 }  // namespace net