Added Net logging to FileStream.

net/base/file_stream_win.cc

Index: net/base/file_stream_win.cc
diff --git a/net/base/file_stream_win.cc b/net/base/file_stream_win.cc
index 07d365f0597b1ef6178f7dd742a92263d8c46d66..4987b35b0533daec732d9e88404e2cbba8be7410 100644
--- a/net/base/file_stream_win.cc
+++ b/net/base/file_stream_win.cc
@@ -1,4 +1,4 @@
-// Copyright (c) 2011 The Chromium Authors. All rights reserved.
+// Copyright (c) 2012 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.
 
@@ -12,6 +12,7 @@
 #include "base/metrics/histogram.h"
 #include "base/threading/thread_restrictions.h"
 #include "net/base/file_stream_metrics.h"
+#include "net/base/file_stream_net_log_parameters.h"
 #include "net/base/net_errors.h"
 
 namespace net {
@@ -36,7 +37,18 @@ static void IncrementOffset(OVERLAPPED* overlapped, DWORD count) {
 
 namespace {
 
-int RecordAndMapError(int error, FileErrorSource source, bool record_uma) {
+int RecordAndMapError(int error,
+                      FileErrorSource source,
+                      bool record_uma,
+                      const net::BoundNetLog& bound_net_log) {
+  bound_net_log.AddEvent(
+      net::NetLog::TYPE_FILE_STREAM_ERROR,
+      make_scoped_refptr(
+          new FileStreamErrorParameters(
+              GetFileErrorSourceName(source),
+              error,
+              MapSystemError(error))));
+
   RecordFileError(error, source, record_uma);
   return MapSystemError(error);
 }
@@ -47,9 +59,10 @@ int RecordAndMapError(int error, FileErrorSource source, bool record_uma) {
 
 class FileStream::AsyncContext : public MessageLoopForIO::IOHandler {
  public:
-  AsyncContext(FileStream* owner)
-      : owner_(owner), context_(), is_closing_(false),
-        record_uma_(false), error_source_(FILE_ERROR_SOURCE_COUNT) {
+  explicit AsyncContext(const net::BoundNetLog& bound_net_log)
+      : context_(), is_closing_(false),
+        record_uma_(false), bound_net_log_(bound_net_log),
+        error_source_(FILE_ERROR_SOURCE_COUNT) {
     context_.handler = this;
   }
   ~AsyncContext();
@@ -69,11 +82,11 @@ class FileStream::AsyncContext : public MessageLoopForIO::IOHandler {
   virtual void OnIOCompleted(MessageLoopForIO::IOContext* context,
                              DWORD bytes_read, DWORD error);
 
-  FileStream* owner_;
   MessageLoopForIO::IOContext context_;
   CompletionCallback callback_;
   bool is_closing_;
   bool record_uma_;
+  net::BoundNetLog bound_net_log_;
   FileErrorSource error_source_;
 };
 
@@ -109,8 +122,10 @@ void FileStream::AsyncContext::OnIOCompleted(
   }
 
   int result = static_cast<int>(bytes_read);
-  if (error && error != ERROR_HANDLE_EOF)
-    result = RecordAndMapError(error, error_source_, record_uma_);
+  if (error && error != ERROR_HANDLE_EOF) {
+    result = RecordAndMapError(error, error_source_, record_uma_,
+                               bound_net_log_);
+  }
 
   if (bytes_read)
     IncrementOffset(&context->overlapped, bytes_read);
@@ -122,22 +137,29 @@ void FileStream::AsyncContext::OnIOCompleted(
 
 // FileStream ------------------------------------------------------------
 
-FileStream::FileStream()
-    : file_(INVALID_HANDLE_VALUE),
+FileStream::FileStream(net::NetLog* net_log)
+    : file_(base::kInvalidPlatformFileValue),
       open_flags_(0),
       auto_closed_(true),
-      record_uma_(false) {
+      record_uma_(false),
+      bound_net_log_(net::BoundNetLog::Make(net_log,
+                                            net::NetLog::SOURCE_FILESTREAM)) {
+  bound_net_log_.BeginEvent(net::NetLog::TYPE_FILE_STREAM_ALIVE, NULL);
 }
 
-FileStream::FileStream(base::PlatformFile file, int flags)
+FileStream::FileStream(base::PlatformFile file, int flags, net::NetLog* net_log)
     : file_(file),
       open_flags_(flags),
       auto_closed_(false),
-      record_uma_(false) {
+      record_uma_(false),
+      bound_net_log_(net::BoundNetLog::Make(net_log,
+                                            net::NetLog::SOURCE_FILESTREAM)) {
+  bound_net_log_.BeginEvent(net::NetLog::TYPE_FILE_STREAM_ALIVE, NULL);
+
   // 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));
+    async_context_.reset(new AsyncContext(bound_net_log_));
     MessageLoopForIO::current()->RegisterIOHandler(file_,
                                                    async_context_.get());
   }
@@ -146,9 +168,12 @@ FileStream::FileStream(base::PlatformFile file, int flags)
 FileStream::~FileStream() {
   if (auto_closed_)
     Close();
+
+  bound_net_log_.EndEvent(net::NetLog::TYPE_FILE_STREAM_ALIVE, NULL);
 }
 
 void FileStream::Close() {
+  bound_net_log_.AddEvent(net::NetLog::TYPE_FILE_STREAM_CLOSE, NULL);
   if (file_ != INVALID_HANDLE_VALUE)
     CancelIo(file_);
 
@@ -156,6 +181,8 @@ void FileStream::Close() {
   if (file_ != INVALID_HANDLE_VALUE) {
     CloseHandle(file_);
     file_ = INVALID_HANDLE_VALUE;
+
+    bound_net_log_.EndEvent(net::NetLog::TYPE_FILE_STREAM_OPEN, NULL);
   }
 }
 
@@ -165,16 +192,27 @@ int FileStream::Open(const FilePath& path, int open_flags) {
     return ERR_UNEXPECTED;
   }
 
+  bound_net_log_.BeginEvent(
+      net::NetLog::TYPE_FILE_STREAM_OPEN,
+      make_scoped_refptr(
+          new net::NetLogStringParameter("file_name",
+                                         path.AsUTF8Unsafe())));
+
   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 RecordAndMapError(error, FILE_ERROR_SOURCE_OPEN, record_uma_);
+    int net_error = RecordAndMapError(error,
+                                      FILE_ERROR_SOURCE_OPEN,
+                                      record_uma_,
+                                      bound_net_log_);
+    bound_net_log_.EndEvent(net::NetLog::TYPE_FILE_STREAM_OPEN, NULL);
+    return net_error;
   }
 
   if (open_flags_ & base::PLATFORM_FILE_ASYNC) {
-    async_context_.reset(new AsyncContext(this));
+    async_context_.reset(new AsyncContext(bound_net_log_));
     if (record_uma_)
       async_context_->EnableErrorStatistics();
     MessageLoopForIO::current()->RegisterIOHandler(file_,
@@ -200,7 +238,10 @@ int64 FileStream::Seek(Whence whence, int64 offset) {
   if (!SetFilePointerEx(file_, distance, &result, move_method)) {
     DWORD error = GetLastError();
     LOG(WARNING) << "SetFilePointerEx failed: " << error;
-    return RecordAndMapError(error, FILE_ERROR_SOURCE_SEEK, record_uma_);
+    return RecordAndMapError(error,
+                             FILE_ERROR_SOURCE_SEEK,
+                             record_uma_,
+                             bound_net_log_);
   }
   if (async_context_.get()) {
     async_context_->set_error_source(FILE_ERROR_SOURCE_SEEK);
@@ -223,7 +264,10 @@ int64 FileStream::Available() {
   if (!GetFileSizeEx(file_, &file_size)) {
     DWORD error = GetLastError();
     LOG(WARNING) << "GetFileSizeEx failed: " << error;
-    return RecordAndMapError(error, FILE_ERROR_SOURCE_GET_SIZE, record_uma_);
+    return RecordAndMapError(error,
+                             FILE_ERROR_SOURCE_GET_SIZE,
+                             record_uma_,
+                             bound_net_log_);
   }
 
   return file_size.QuadPart - cur_pos;
@@ -259,7 +303,10 @@ int FileStream::Read(
       rv = 0;  // Report EOF by returning 0 bytes read.
     } else {
       LOG(WARNING) << "ReadFile failed: " << error;
-      rv = RecordAndMapError(error, FILE_ERROR_SOURCE_READ, record_uma_);
+      rv = RecordAndMapError(error,
+                             FILE_ERROR_SOURCE_READ,
+                             record_uma_,
+                             bound_net_log_);
     }
   } else if (overlapped) {
     async_context_->IOCompletionIsPending(callback);
@@ -318,7 +365,10 @@ int FileStream::Write(
       rv = ERR_IO_PENDING;
     } else {
       LOG(WARNING) << "WriteFile failed: " << error;
-      rv = RecordAndMapError(error, FILE_ERROR_SOURCE_WRITE, record_uma_);
+      rv = RecordAndMapError(error,
+                             FILE_ERROR_SOURCE_WRITE,
+                             record_uma_,
+                             bound_net_log_);
     }
   } else if (overlapped) {
     async_context_->IOCompletionIsPending(callback);
@@ -342,7 +392,8 @@ int FileStream::Flush() {
 
   return RecordAndMapError(GetLastError(),
                            FILE_ERROR_SOURCE_FLUSH,
-                           record_uma_);
+                           record_uma_,
+                           bound_net_log_);
 }
 
 int64 FileStream::Truncate(int64 bytes) {
@@ -351,7 +402,7 @@ int64 FileStream::Truncate(int64 bytes) {
   if (!IsOpen())
     return ERR_UNEXPECTED;
 
-  // We better be open for reading.
+  // We'd better be open for writing.
   DCHECK(open_flags_ & base::PLATFORM_FILE_WRITE);
 
   // Seek to the position to truncate from.
@@ -364,7 +415,10 @@ int64 FileStream::Truncate(int64 bytes) {
   if (!result) {
     DWORD error = GetLastError();
     LOG(WARNING) << "SetEndOfFile failed: " << error;
-    return RecordAndMapError(error, FILE_ERROR_SOURCE_SET_EOF, record_uma_);
+    return RecordAndMapError(error,
+                             FILE_ERROR_SOURCE_SET_EOF,
+                             record_uma_,
+                             bound_net_log_);
   }
 
   // Success.
@@ -378,4 +432,48 @@ void FileStream::EnableErrorStatistics() {
     async_context_->EnableErrorStatistics();
 }
 
+void FileStream::SetBoundNetLogSource(
+    const net::BoundNetLog& owner_bound_net_log) {
+  if ((owner_bound_net_log.source().id == net::NetLog::Source::kInvalidId) &&
+      (bound_net_log_.source().id == net::NetLog::Source::kInvalidId)) {
+    // Both |BoundNetLog|s are invalid.
+    return;
+  }
+
+  // Should never connect to itself.
+  DCHECK_NE(bound_net_log_.source().id, owner_bound_net_log.source().id);
+
+  if ((owner_bound_net_log.source().id == net::NetLog::Source::kInvalidId) &&
+      (bound_net_log_.source().id == net::NetLog::Source::kInvalidId)) {

[mmenke, 2012/01/31 23:20:58]

Think you want != here.

[ahendrickson, 2012/02/01 00:13:29]

Removed this portion of the code . . .

+    // Both |BoundNetLog|s are valid.  Cross-link the sources.
+    bound_net_log_.AddEvent(
+        net::NetLog::TYPE_FILE_STREAM_BOUND_TO_OWNER,
+        make_scoped_refptr(
+            new net::NetLogSourceParameter("source_dependency",
+                                           owner_bound_net_log.source())));
+
+    owner_bound_net_log.AddEvent(
+        net::NetLog::TYPE_FILE_STREAM_SOURCE,
+        make_scoped_refptr(
+            new net::NetLogSourceParameter("source_dependency",
+                                           bound_net_log_.source())));
+
+    return;
+  }
+
+  if (bound_net_log_.source().id == net::NetLog::Source::kInvalidId) {
+    // |bound_net_log_| is invalid.  Add an event to the owner.
+    owner_bound_net_log.AddEvent(
+        net::NetLog::TYPE_FILE_STREAM_SOURCE,
+        make_scoped_refptr(
+            new net::NetLogStringParameter("source", "Unknown")));

[mmenke, 2012/01/31 23:20:58]

Problem with this is you'd need to update the event docs for both events
accordingly.

I think just always using the code using in the both not invalid case would be
fine, though perhaps I'm in the minority.

[ahendrickson, 2012/02/01 00:13:29]

OK, I thought it might be a problem.  Going back to calling them even if they
are not both valid.

+  } else {
+    // |owner_bound_net_log| is invalid.  Add an event indicating transfer of
+    // ownership.
+    bound_net_log_.AddEvent(
+        net::NetLog::TYPE_FILE_STREAM_BOUND_TO_OWNER,
+        make_scoped_refptr(new net::NetLogStringParameter("owner", "Unknown")));
+  }
+}
+
 }  // namespace net