If CreateDirectory() fails during extension unpacking, log the exact OS call that failed.

This change is designed to help understand bug 35198, which we can not reproduce locally.

BUG=35198
TEST=manual

Review URL: http://codereview.chromium.org/2714016

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@49703 0039d316-1c4b-4281-b951-d872f2087c98

3 files changed, 63 insertions, 23 deletions

diff --git a/base/file_util.h b/base/file_util.h
index b2e176b..a16c5c72 100644
--- a/base/file_util.h
+++ b/base/file_util.h
@@ -281,6 +281,14 @@ bool CreateNewTempDirectory(const FilePath::StringType& prefix,
 // already exists.  The directory is only readable by the current user.
 bool CreateDirectory(const FilePath& full_path);
 
+#if defined(OS_WIN)
+// Added for debugging an issue where CreateDirectory() fails.  LOG(*) does
+// not work, because the failure happens in a sandboxed process.
+// TODO(skerner): Remove once crbug/35198 is resolved.
+bool CreateDirectoryExtraLogging(const FilePath& full_path,
+                                 std::ostream& error);
+#endif  // defined (OS_WIN)
+
 // Returns the file size. Returns true on success.
 bool GetFileSize(const FilePath& file_path, int64* file_size);
 
diff --git a/base/file_util_win.cc b/base/file_util_win.cc
index dc15ea0..8a15370 100644
--- a/base/file_util_win.cc
+++ b/base/file_util_win.cc
@@ -587,22 +587,32 @@ bool CreateNewTempDirectory(const FilePath::StringType& prefix,
   return CreateTemporaryDirInDir(system_temp_dir, prefix, new_temp_path);
 }
 
+bool CreateDirectory(const FilePath& full_path) {
+  return file_util::CreateDirectoryExtraLogging(full_path, LOG(INFO));
+}
+
 // TODO(skerner): Extra logging has been added to understand crbug/35198 .
 // Remove it once we get a log from a user who can reproduce the issue.
-bool CreateDirectory(const FilePath& full_path) {
-  LOG(INFO) << "Enter CreateDirectory: full_path = " << full_path.value();
+bool CreateDirectoryExtraLogging(const FilePath& full_path,
+                                 std::ostream& log) {
+  log << "Enter CreateDirectory: full_path = " << full_path.value()
+      << std::endl;
   // If the path exists, we've succeeded if it's a directory, failed otherwise.
   const wchar_t* full_path_str = full_path.value().c_str();
   DWORD fileattr = ::GetFileAttributes(full_path_str);
-  LOG(INFO) << "::GetFileAttributes() returned " << fileattr;
-  if (fileattr != INVALID_FILE_ATTRIBUTES) {
+  log << "::GetFileAttributes() returned " << fileattr << std::endl;
+  if (fileattr == INVALID_FILE_ATTRIBUTES) {
+    DWORD fileattr_error = GetLastError();
+    log << "::GetFileAttributes() failed.  GetLastError() = "
+        << fileattr_error << std::endl;
+  } else {
     if ((fileattr & FILE_ATTRIBUTE_DIRECTORY) != 0) {
-      LOG(INFO) << "CreateDirectory(" << full_path_str << "), " <<
-          "directory already exists.";
+      log << "CreateDirectory(" << full_path_str << "), "
+          << "directory already exists." << std::endl;
       return true;
     } else {
-      LOG(WARNING) << "CreateDirectory(" << full_path_str << "), " <<
-          "conflicts with existing file.";
+      log << "CreateDirectory(" << full_path_str << "), "
+          << "conflicts with existing file." << std::endl;
     }
   }
 
@@ -613,35 +623,49 @@ bool CreateDirectory(const FilePath& full_path) {
   // directories starting with the highest-level missing parent.
   FilePath parent_path(full_path.DirName());
   if (parent_path.value() == full_path.value()) {
-    LOG(INFO) << "Can't create directory: parent_path " <<
-        parent_path.value() << " should not equal full_path " <<
-        full_path.value();
+    log << "Can't create directory: parent_path " << parent_path.value()
+        << " should not equal full_path " << full_path.value()
+        << std::endl;
     return false;
   }
   if (!CreateDirectory(parent_path)) {
-    LOG(INFO) << "Failed to create one of the parent directories: " <<
-        parent_path.value();
+    log << "Failed to create one of the parent directories: "
+        << parent_path.value() << std::endl;
     return false;
   }
 
-  LOG(INFO) << "About to call ::CreateDirectory() with full_path_str = " <<
-      full_path_str;
+  log << "About to call ::CreateDirectory() with full_path_str = "
+      << full_path_str << std::endl;
   if (!::CreateDirectory(full_path_str, NULL)) {
     DWORD error_code = ::GetLastError();
+    log << "CreateDirectory() gave last error " << error_code << std::endl;
+
+    DWORD fileattr = GetFileAttributes(full_path.value().c_str());
+    if (fileattr == INVALID_FILE_ATTRIBUTES) {
+      DWORD fileattr_error = ::GetLastError();
+      log << "GetFileAttributes() failed, GetLastError() = "
+          << fileattr_error << std::endl;
+    } else {
+      log << "GetFileAttributes() returned " << fileattr << std::endl;
+      log << "Is the path a directory: "
+          << ((fileattr & FILE_ATTRIBUTE_DIRECTORY) != 0) << std::endl;
+    }
     if (error_code == ERROR_ALREADY_EXISTS && DirectoryExists(full_path)) {
       // This error code doesn't indicate whether we were racing with someone
       // creating the same directory, or a file with the same path, therefore
       // we check.
-      LOG(INFO) << "Race condition? Directory already exists: " <<
-          full_path.value();
+      log << "Race condition? Directory already exists: "
+          << full_path.value() << std::endl;
       return true;
     } else {
-      LOG(WARNING) << "Failed to create directory " << full_path_str <<
-          ", le=" << error_code;
+      DWORD dir_exists_error = ::GetLastError();
+      log << "Failed to create directory " << full_path_str << std::endl;
+      log << "GetLastError() for DirectoryExists() is "
+          << dir_exists_error << std::endl;
       return false;
     }
   } else {
-    LOG(INFO) << "::CreateDirectory() worked.";
+    log << "::CreateDirectory() succeeded." << std::endl;
     return true;
   }
 }
diff --git a/chrome/common/extensions/extension_unpacker.cc b/chrome/common/extensions/extension_unpacker.cc
index 8c634e2..599aa11 100644
--- a/chrome/common/extensions/extension_unpacker.cc
+++ b/chrome/common/extensions/extension_unpacker.cc
@@ -140,15 +140,23 @@ bool ExtensionUnpacker::Run() {
   // <profile>/Extensions/INSTALL_TEMP/<version>
   temp_install_dir_ =
     extension_path_.DirName().AppendASCII(filenames::kTempExtensionName);
-  if (!file_util::CreateDirectory(temp_install_dir_)) {
+
 #if defined(OS_WIN)
-    std::string dir_string = WideToUTF8(temp_install_dir_.value());
+  std::ostringstream log_stream;
+  std::string dir_string = WideToUTF8(temp_install_dir_.value());
+  log_stream << kCouldNotCreateDirectoryError << dir_string << std::endl;
+  if (!file_util::CreateDirectoryExtraLogging(temp_install_dir_, log_stream)) {
+    log_stream.flush();
+    SetError(log_stream.str());
+    return false;
+  }
 #else
+  if (!file_util::CreateDirectory(temp_install_dir_)) {
     std::string dir_string = temp_install_dir_.value();
-#endif
     SetError(kCouldNotCreateDirectoryError + dir_string);
     return false;
   }
+#endif
 
   if (!Unzip(extension_path_, temp_install_dir_)) {
     SetError(kCouldNotUnzipExtension);