Added net logging to BaseFile.

content/browser/download/base_file.cc

Index: content/browser/download/base_file.cc
diff --git a/content/browser/download/base_file.cc b/content/browser/download/base_file.cc
index a9da47f726876a9335794e3d602789b0f8e3aba0..f11cdc07757b8fc535e18096469c863abd540e22 100644
--- a/content/browser/download/base_file.cc
+++ b/content/browser/download/base_file.cc
@@ -11,6 +11,7 @@
 #include "base/stringprintf.h"
 #include "base/threading/thread_restrictions.h"
 #include "base/utf_string_conversions.h"
+#include "content/browser/download/download_net_log_parameters.h"
 #include "content/browser/download/download_stats.h"
 #include "content/public/browser/browser_thread.h"
 #include "content/public/browser/content_browser_client.h"
@@ -31,12 +32,17 @@ using content::BrowserThread;
 
 namespace {
 
-#define LOG_ERROR(o, e)  LogError(__FILE__, __LINE__, __FUNCTION__, o, e)
+#define LOG_ERROR(o, e)  \
+  LogError(__FILE__, __LINE__, __FUNCTION__, bound_net_log_, o, e)
 
 // Logs the value and passes error on through, converting to a |net::Error|.
 // Returns |ERR_UNEXPECTED| if the value is not in the enum.
-net::Error LogError(const char* file, int line, const char* func,
-                    const char* operation, int error) {
+net::Error LogError(const char* file,
+                    int line,
+                    const char* func,
+                    const net::BoundNetLog& bound_net_log,
+                    const char* operation,
+                    int error) {
   const char* err_string = "";
   net::Error net_error = net::OK;
 
@@ -63,6 +69,11 @@ net::Error LogError(const char* file, int line, const char* func,
   VLOG(1) << " " << func << "(): " << operation
           << "() returned error " << error << " (" << err_string << ")";
 
+  bound_net_log.AddEvent(
+      net::NetLog::TYPE_DOWNLOAD_FILE_ERROR,
+      make_scoped_refptr(
+          new download_net_logs::FileErrorParameters(operation, net_error)));
+
   return net_error;
 }
 
@@ -196,7 +207,8 @@ BaseFile::BaseFile(const FilePath& full_path,
                    int64 received_bytes,
                    bool calculate_hash,
                    const std::string& hash_state,
-                   const linked_ptr<net::FileStream>& file_stream)
+                   const linked_ptr<net::FileStream>& file_stream,
+                   const net::BoundNetLog& bound_net_log)
     : full_path_(full_path),
       source_url_(source_url),
       referrer_url_(referrer_url),
@@ -205,11 +217,14 @@ BaseFile::BaseFile(const FilePath& full_path,
       start_tick_(base::TimeTicks::Now()),
       power_save_blocker_(PowerSaveBlocker::kPowerSaveBlockPreventSystemSleep),
       calculate_hash_(calculate_hash),
-      detached_(false) {
+      detached_(false),
+      bound_net_log_(bound_net_log) {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
   memcpy(sha256_hash_, kEmptySha256Hash, kSha256HashLen);
-  if (file_stream_.get())
+  if (file_stream_.get()) {
+    file_stream_->SetBoundNetLogSource(bound_net_log_);
     file_stream_->EnableErrorStatistics();
+  }
 
   if (calculate_hash_) {
     secure_hash_.reset(crypto::SecureHash::Create(crypto::SecureHash::SHA256));
@@ -253,9 +268,16 @@ net::Error BaseFile::AppendDataToFile(const char* data, size_t data_len) {
 
   // NOTE(benwells): The above DCHECK won't be present in release builds,
   // so we log any occurences to see how common this error is in the wild.
-  if (detached_)
+  if (detached_) {
     download_stats::RecordDownloadCount(
         download_stats::APPEND_TO_DETACHED_FILE_COUNT);
+  }
+
+  bound_net_log_.AddEvent(

[mmenke1, 2012/02/03 18:32:32]

This should be wrapped in:

if (bound_net_log_.IsLoggingAllEvents())

[ahendrickson, 2012/02/04 05:27:14]

Done.

+      net::NetLog::TYPE_DOWNLOAD_FILE_WRITTEN,
+      make_scoped_refptr(
+          new download_net_logs::FileWrittenParameters(
+              data_len, bytes_so_far_)));
 
   if (!file_stream_.get())
     return LOG_ERROR("get", net::ERR_INVALID_HANDLE);
@@ -292,9 +314,8 @@ net::Error BaseFile::AppendDataToFile(const char* data, size_t data_len) {
     bytes_so_far_ += write_size;
   }
 
-  // TODO(ahendrickson) -- Uncomment these when the functions are available.
-   download_stats::RecordDownloadWriteSize(data_len);
-   download_stats::RecordDownloadWriteLoopCount(write_count);
+  download_stats::RecordDownloadWriteSize(data_len);
+  download_stats::RecordDownloadWriteLoopCount(write_count);
 
   if (calculate_hash_)
     secure_hash_->Update(data, data_len);
@@ -309,6 +330,12 @@ net::Error BaseFile::Rename(const FilePath& new_path) {
   // it will be overwritten by closing the file.
   bool saved_in_progress = in_progress();
 
+  bound_net_log_.AddEvent(
+      net::NetLog::TYPE_DOWNLOAD_FILE_RENAMED,
+      make_scoped_refptr(
+          new download_net_logs::FileRenamedParameters(
+              full_path_.AsUTF8Unsafe(), new_path.AsUTF8Unsafe())));
+
   // If the new path is same as the old one, there is no need to perform the
   // following renaming logic.
   if (new_path == full_path_) {
@@ -376,16 +403,22 @@ net::Error BaseFile::Rename(const FilePath& new_path) {
 
 void BaseFile::Detach() {
   detached_ = true;
+  bound_net_log_.AddEvent(net::NetLog::TYPE_DOWNLOAD_FILE_DETACHED, NULL);
 }
 
 void BaseFile::Cancel() {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
   DCHECK(!detached_);
 
+  bound_net_log_.AddEvent(net::NetLog::TYPE_DOWNLOAD_FILE_CANCELED, NULL);

[mmenke1, 2012/02/03 18:32:32]

I'd suggest using the generic NetLog::TYPE_CANCELLED here.  This allows some
future net-internals code to identify cancelled things easily.

[ahendrickson, 2012/02/04 05:27:14]

Done.

+
   Close();
 
-  if (!full_path_.empty())
+  if (!full_path_.empty()) {
+    bound_net_log_.AddEvent(net::NetLog::TYPE_DOWNLOAD_FILE_DELETED, NULL);
+
     file_util::Delete(full_path_, false);
+  }
 }
 
 void BaseFile::Finish() {
@@ -449,7 +482,8 @@ void BaseFile::AnnotateWithSourceInformation() {
 }
 
 void BaseFile::CreateFileStream() {
-  file_stream_.reset(new net::FileStream(NULL));
+  file_stream_.reset(new net::FileStream(bound_net_log_.net_log()));
+  file_stream_->SetBoundNetLogSource(bound_net_log_);
 }
 
 net::Error BaseFile::Open() {
@@ -457,6 +491,12 @@ net::Error BaseFile::Open() {
   DCHECK(!detached_);
   DCHECK(!full_path_.empty());
 
+  bound_net_log_.BeginEvent(
+      net::NetLog::TYPE_DOWNLOAD_FILE_OPENED,
+      make_scoped_refptr(
+          new download_net_logs::FileOpenedParameters(
+              full_path_.AsUTF8Unsafe(), bytes_so_far_)));
+
   // Create a new file stream if it is not provided.
   if (!file_stream_.get()) {
     CreateFileStream();
@@ -464,28 +504,39 @@ net::Error BaseFile::Open() {
     int open_result = file_stream_->Open(
         full_path_,
         base::PLATFORM_FILE_OPEN_ALWAYS | base::PLATFORM_FILE_WRITE);
-    if (open_result != net::OK) {
-      file_stream_.reset();
-      return LOG_ERROR("Open", open_result);
-    }
+    if (open_result != net::OK)
+      return AbortOpen(LOG_ERROR("Open", open_result));
 
     // We may be re-opening the file after rename. Always make sure we're
     // writing at the end of the file.
     int64 seek_result = file_stream_->Seek(net::FROM_END, 0);
-    if (seek_result < 0) {
-      file_stream_.reset();
-      return LOG_ERROR("Seek", seek_result);
-    }
+    if (seek_result < 0)
+      return AbortOpen(LOG_ERROR("Seek", seek_result));
+  } else {
+    file_stream_->SetBoundNetLogSource(bound_net_log_);
   }
 
 #if defined(OS_WIN)
   AnnotateWithSourceInformation();
 #endif
+
   return net::OK;
 }
 
+net::Error BaseFile::AbortOpen(net::Error net_error) {

[Randy Smith (Not in Mondays), 2012/02/02 20:05:54]

nit: I don't think that there's particular value to the whitespace in this
routine.

(FWIW, I actually don't think the gain in code collapsing is worth the extra
routine; you're replacing two lines + a closing brace with one in two places,
but adding four lines + a closing brace here and a declaration in the .h file.)

[ahendrickson, 2012/02/02 22:23:36]

This function is called in 2 places (now 3, but I've renamed it to ClearStream).

Additionally, whenever file_stream_ is reset to NULL I want to have the EndEvent
occur for OPEN.

I think this is valuable enough to keep it as a function.

[Randy Smith (Not in Mondays), 2012/02/03 17:02:17]

This comment had two parts, and you only responded to the second part.  Could
you adjust the routine whitespace?

(I also don't feel like you responded to the arguments in my FWIW, but I also
don't feel strongly about those arguments, so I'm not going to worry about it.)

[ahendrickson, 2012/02/03 17:29:32]

Ah, sorry about not responding to the whitespace portion of the comment -- I
simply changed it without mentioning it!

+  file_stream_.reset();
+
+  bound_net_log_.EndEvent(net::NetLog::TYPE_DOWNLOAD_FILE_OPENED, NULL);
+
+  return net_error;
+}
+
+
 void BaseFile::Close() {
   DCHECK(BrowserThread::CurrentlyOn(BrowserThread::FILE));
+
+  bound_net_log_.AddEvent(net::NetLog::TYPE_DOWNLOAD_FILE_CLOSED, NULL);
+
   if (file_stream_.get()) {
 #if defined(OS_CHROMEOS)
     // Currently we don't really care about the return value, since if it fails
@@ -494,6 +545,8 @@ void BaseFile::Close() {
 #endif
     file_stream_->Close();
     file_stream_.reset();
+
+    bound_net_log_.EndEvent(net::NetLog::TYPE_DOWNLOAD_FILE_OPENED, NULL);
   }
 }