Support initializing logging with a file descriptor rather than a path.

This CL adds an optional file descriptor to LoggingSettings, which can
be used to initialize logging to an already open file. Previously,
logging to a file required passing a path and letting the logging
system open() it for append. Passing a file-descriptor means that a
process can be sandboxed to have no access to the log directory, but
can still be passed a file-descriptor to log to.

This is needed for the Network Service on ChromeOS, whose logging needs
to be reinitialized to a new location after it's already started.

Bug: 977415
Change-Id: I2d07dc13a7e9f0f57d0802e4816628c181f183cd
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/1699477
Commit-Queue: Robbie McElrath <rmcelrath@chromium.org>
Reviewed-by: John Abd-El-Malek <jam@chromium.org>
Reviewed-by: Achuith Bhandarkar <achuith@chromium.org>
Reviewed-by: Will Harris <wfh@chromium.org>
Reviewed-by: Wez <wez@chromium.org>
Cr-Commit-Position: refs/heads/master@{#688754}

ash/shell/content/shell_with_content_main.cc

@@ -18,7 +18,7 @@ int main(int argc, const char** argv) {
   log_filename = log_filename.AppendASCII("ash_shell.log");
   logging::LoggingSettings settings;
   settings.logging_dest = logging::LOG_TO_ALL;
-  settings.log_file = log_filename.value().c_str();
+  settings.log_file_path = log_filename.value().c_str();
   settings.delete_old = logging::DELETE_OLD_LOG_FILE;
   logging::InitLogging(settings);
   logging::SetLogItems(true /* process_id */, true /* thread_id */,

base/logging.cc

@@ -119,6 +119,10 @@ typedef pthread_mutex_t* MutexHandle;
 #include "base/posix/safe_strerror.h"
 #endif
 
+#if defined(OS_CHROMEOS)
+#include "base/files/scoped_file.h"
+#endif
+
 namespace logging {
 
 namespace {
@@ -313,52 +317,52 @@ bool InitializeLogFileHandle() {
     g_log_file_name = new PathString(GetDefaultLogFile());
   }
 
-  if ((g_logging_destination & LOG_TO_FILE) != 0) {
+  if ((g_logging_destination & LOG_TO_FILE) == 0)
+    return true;
+
 #if defined(OS_WIN)
-    // The FILE_APPEND_DATA access mask ensures that the file is atomically
-    // appended to across accesses from multiple threads.
-    // https://msdn.microsoft.com/en-us/library/windows/desktop/aa364399(v=vs.85).aspx
-    // https://msdn.microsoft.com/en-us/library/windows/desktop/aa363858(v=vs.85).aspx
+  // The FILE_APPEND_DATA access mask ensures that the file is atomically
+  // appended to across accesses from multiple threads.
+  // https://msdn.microsoft.com/en-us/library/windows/desktop/aa364399(v=vs.85).aspx
+  // https://msdn.microsoft.com/en-us/library/windows/desktop/aa363858(v=vs.85).aspx
+  g_log_file = CreateFile(base::as_wcstr(*g_log_file_name), FILE_APPEND_DATA,
+                          FILE_SHARE_READ | FILE_SHARE_WRITE, nullptr,
+                          OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, nullptr);
+  if (g_log_file == INVALID_HANDLE_VALUE || g_log_file == nullptr) {
+    // We are intentionally not using FilePath or FileUtil here to reduce the
+    // dependencies of the logging implementation. For e.g. FilePath and
+    // FileUtil depend on shell32 and user32.dll. This is not acceptable for
+    // some consumers of base logging like chrome_elf, etc.
+    // Please don't change the code below to use FilePath.
+    // try the current directory
+    base::char16 system_buffer[MAX_PATH];
+    system_buffer[0] = 0;
+    DWORD len = ::GetCurrentDirectory(base::size(system_buffer),
+                                      base::as_writable_wcstr(system_buffer));
+    if (len == 0 || len > base::size(system_buffer))
+      return false;
+
+    *g_log_file_name = system_buffer;
+    // Append a trailing backslash if needed.
+    if (g_log_file_name->back() != L'\\')
+      *g_log_file_name += STRING16_LITERAL("\\");
+    *g_log_file_name += STRING16_LITERAL("debug.log");
+
     g_log_file = CreateFile(base::as_wcstr(*g_log_file_name), FILE_APPEND_DATA,
                             FILE_SHARE_READ | FILE_SHARE_WRITE, nullptr,
                             OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, nullptr);
     if (g_log_file == INVALID_HANDLE_VALUE || g_log_file == nullptr) {
-      // We are intentionally not using FilePath or FileUtil here to reduce the
-      // dependencies of the logging implementation. For e.g. FilePath and
-      // FileUtil depend on shell32 and user32.dll. This is not acceptable for
-      // some consumers of base logging like chrome_elf, etc.
-      // Please don't change the code below to use FilePath.
-      // try the current directory
-      base::char16 system_buffer[MAX_PATH];
-      system_buffer[0] = 0;
-      DWORD len = ::GetCurrentDirectory(base::size(system_buffer),
-                                        base::as_writable_wcstr(system_buffer));
-      if (len == 0 || len > base::size(system_buffer))
-        return false;
-
-      *g_log_file_name = system_buffer;
-      // Append a trailing backslash if needed.
-      if (g_log_file_name->back() != L'\\')
-        *g_log_file_name += STRING16_LITERAL("\\");
-      *g_log_file_name += STRING16_LITERAL("debug.log");
-
-      g_log_file =
-          CreateFile(base::as_wcstr(*g_log_file_name), FILE_APPEND_DATA,
-                     FILE_SHARE_READ | FILE_SHARE_WRITE, nullptr, OPEN_ALWAYS,
-                     FILE_ATTRIBUTE_NORMAL, nullptr);
-      if (g_log_file == INVALID_HANDLE_VALUE || g_log_file == nullptr) {
-        g_log_file = nullptr;
-        return false;
-      }
+      g_log_file = nullptr;
+      return false;
     }
+  }
 #elif defined(OS_POSIX) || defined(OS_FUCHSIA)
-    g_log_file = fopen(g_log_file_name->c_str(), "a");
-    if (g_log_file == nullptr)
-      return false;
+  g_log_file = fopen(g_log_file_name->c_str(), "a");
+  if (g_log_file == nullptr)
+    return false;
 #else
 #error Unsupported platform
 #endif
-  }
 
   return true;
 }
@@ -379,6 +383,11 @@ void CloseLogFileUnlocked() {
 
   CloseFile(g_log_file);
   g_log_file = nullptr;
+
+  // If we initialized logging via an externally-provided file descriptor, we
+  // won't have a log path set and shouldn't try to reopen the log file.
+  if (!g_log_file_name)
+    g_logging_destination &= ~LOG_TO_FILE;
 }
 
 }  // namespace
@@ -401,6 +410,7 @@ bool BaseInitLoggingImpl(const LoggingSettings& settings) {
   CHECK_EQ(settings.logging_dest & ~(LOG_TO_SYSTEM_DEBUG_LOG | LOG_TO_STDERR),
            0u);
 #endif
+
   base::CommandLine* command_line = base::CommandLine::ForCurrentProcess();
   // Don't bother initializing |g_vlog_info| unless we use one of the
   // vlog switches.
@@ -439,17 +449,25 @@ bool BaseInitLoggingImpl(const LoggingSettings& settings) {
     return true;
 
 #if defined(OS_POSIX) || defined(OS_FUCHSIA)
-  LoggingLock::Init(settings.lock_log, settings.log_file);
+  LoggingLock::Init(settings.lock_log, settings.log_file_path);
   LoggingLock logging_lock;
 #endif
 
   // Calling InitLogging twice or after some log call has already opened the
   // default log file will re-initialize to the new options.
   CloseLogFileUnlocked();
 
+#if defined(OS_CHROMEOS)
+  if (settings.log_file) {
+    DCHECK(!settings.log_file_path);
+    g_log_file = settings.log_file;
+    return true;
+  }
+#endif
+
   if (!g_log_file_name)
     g_log_file_name = new PathString();
-  *g_log_file_name = settings.log_file;
+  *g_log_file_name = settings.log_file_path;
   if (settings.delete_old == DELETE_OLD_LOG_FILE)
     DeleteFilePath(*g_log_file_name);
 
@@ -1078,6 +1096,25 @@ void CloseLogFile() {
   CloseLogFileUnlocked();
 }
 
+#if defined(OS_CHROMEOS)
+FILE* DuplicateLogFILE() {
+  if ((g_logging_destination & LOG_TO_FILE) == 0 || !InitializeLogFileHandle())
+    return nullptr;
+
+  int log_fd = fileno(g_log_file);
+  if (log_fd == -1)
+    return nullptr;
+  base::ScopedFD dup_fd(dup(log_fd));
+  if (dup_fd == -1)
+    return nullptr;
+  FILE* duplicate = fdopen(dup_fd.get(), "a");
+  if (!duplicate)
+    return nullptr;
+  ignore_result(dup_fd.release());
+  return duplicate;
+}
+#endif
+
 void RawLog(int level, const char* message) {
   if (level >= g_min_log_level && message) {
     size_t bytes_written = 0;

base/logging.h

@@ -26,6 +26,10 @@
 #include "base/template_util.h"
 #include "build/build_config.h"
 
+#if defined(OS_CHROMEOS)
+#include <cstdio>
+#endif
+
 //
 // Optional message capabilities
 // -----------------------------
@@ -214,11 +218,18 @@ struct BASE_EXPORT LoggingSettings {
   // destinations.
   uint32_t logging_dest = LOG_DEFAULT;
 
-  // The three settings below have an effect only when LOG_TO_FILE is
+  // The four settings below have an effect only when LOG_TO_FILE is
   // set in |logging_dest|.
-  const PathChar* log_file = nullptr;
+  const PathChar* log_file_path = nullptr;
   LogLockingState lock_log = LOCK_LOG_FILE;
   OldFileDeletionState delete_old = APPEND_TO_OLD_LOG_FILE;
+#if defined(OS_CHROMEOS)
+  // Contains an optional file that logs should be written to. If present,
+  // |log_file_path| will be ignored, and the logging system will take ownership
+  // of the FILE. If there's an error writing to this file, no fallback paths
+  // will be opened.
+  FILE* log_file = nullptr;
+#endif
 };
 
 // Define different names for the BaseInitLoggingImpl() function depending on
@@ -988,6 +999,14 @@ class BASE_EXPORT ErrnoLogMessage {
 //       after this call.
 BASE_EXPORT void CloseLogFile();
 
+#if defined(OS_CHROMEOS)
+// Returns a new file handle that will write to the same destination as the
+// currently open log file. Returns nullptr if logging to a file is disabled,
+// or if opening the file failed. This is intended to be used to initialize
+// logging in child processes that are unable to open files.
+BASE_EXPORT FILE* DuplicateLogFILE();
+#endif
+
 // Async signal safe logging mechanism.
 BASE_EXPORT void RawLog(int level, const char* message);
 

base/logging_unittest.cc

@@ -260,7 +260,7 @@ void TestForLogToStderr(int log_destinations,
   base::FilePath file_logs_path;
   if (log_destinations & LOG_TO_FILE) {
     file_logs_path = temp_dir.GetPath().Append("file.log");
-    settings.log_file = file_logs_path.value().c_str();
+    settings.log_file_path = file_logs_path.value().c_str();
   }
   InitLogging(settings);
 
@@ -316,6 +316,64 @@ TEST_F(LoggingTest, AlwaysLogErrorsToStderr) {
 }
 #endif
 
+#if defined(OS_CHROMEOS)
+TEST_F(LoggingTest, InitWithFileDescriptor) {
+  const char kErrorLogMessage[] = "something bad happened";
+
+  // Open a file to pass to the InitLogging.
+  base::ScopedTempDir temp_dir;
+  ASSERT_TRUE(temp_dir.CreateUniqueTempDir());
+  base::FilePath file_log_path = temp_dir.GetPath().Append("file.log");
+  FILE* log_file = fopen(file_log_path.value().c_str(), "w");
+  CHECK(log_file);
+
+  // Set up logging.
+  LoggingSettings settings;
+  settings.logging_dest = LOG_TO_FILE;
+  settings.log_file = log_file;
+  InitLogging(settings);
+
+  LOG(ERROR) << kErrorLogMessage;
+
+  // Check the message was written to the log file.
+  std::string written_logs;
+  ASSERT_TRUE(base::ReadFileToString(file_log_path, &written_logs));
+  ASSERT_NE(written_logs.find(kErrorLogMessage), std::string::npos);
+}
+
+TEST_F(LoggingTest, DuplicateLogFile) {
+  const char kErrorLogMessage1[] = "something really bad happened";
+  const char kErrorLogMessage2[] = "some other bad thing happened";
+
+  base::ScopedTempDir temp_dir;
+  ASSERT_TRUE(temp_dir.CreateUniqueTempDir());
+  base::FilePath file_log_path = temp_dir.GetPath().Append("file.log");
+
+  // Set up logging.
+  LoggingSettings settings;
+  settings.logging_dest = LOG_TO_FILE;
+  settings.log_file_path = file_log_path.value().c_str();
+  InitLogging(settings);
+
+  LOG(ERROR) << kErrorLogMessage1;
+
+  // Duplicate the log FILE, close the original (to make sure we actually
+  // duplicated it), and write to the duplicate.
+  FILE* log_file_dup = DuplicateLogFILE();
+  CHECK(log_file_dup);
+  CloseLogFile();
+  fprintf(log_file_dup, "%s\n", kErrorLogMessage2);
+  fflush(log_file_dup);
+
+  // Check the messages were written to the log file.
+  std::string written_logs;
+  ASSERT_TRUE(base::ReadFileToString(file_log_path, &written_logs));
+  ASSERT_NE(written_logs.find(kErrorLogMessage1), std::string::npos);
+  ASSERT_NE(written_logs.find(kErrorLogMessage2), std::string::npos);
+  fclose(log_file_dup);
+}
+#endif  // defined(OS_CHROMEOS)
+
 // Official builds have CHECKs directly call BreakDebugger.
 #if !defined(OFFICIAL_BUILD)
 

base/test/test_suite.cc

@@ -176,7 +176,7 @@ void InitializeLogging() {
 #endif  // defined(OS_FUCHSIA)
 
   logging::LoggingSettings settings;
-  settings.log_file = log_filename.value().c_str();
+  settings.log_file_path = log_filename.value().c_str();
   settings.logging_dest = logging::LOG_TO_ALL;
   settings.delete_old = logging::DELETE_OLD_LOG_FILE;
   logging::InitLogging(settings);

chrome/browser/chromeos/logging.cc

@@ -4,6 +4,8 @@
 
 #include "chrome/browser/chromeos/logging.h"
 
+#include <cstdio>
+
 #include "base/bind.h"
 #include "base/command_line.h"
 #include "base/files/file_path.h"
@@ -15,6 +17,7 @@
 #include "content/public/browser/browser_thread.h"
 #include "content/public/browser/network_service_instance.h"
 #include "content/public/common/network_service_util.h"
+#include "mojo/public/cpp/system/platform_handle.h"
 #include "services/network/public/mojom/network_service.mojom.h"
 
 namespace logging {
@@ -23,7 +26,7 @@ namespace {
 
 // This should be true for exactly the period between the end of
 // InitChromeLogging() and the beginning of CleanupChromeLogging().
-bool chrome_logging_redirected_ = false;
+bool g_chrome_logging_redirected = false;
 
 // This should be set to true for tests that rely on log redirection.
 bool g_force_log_redirection = false;
@@ -37,20 +40,26 @@ void SymlinkSetUp(const base::CommandLine& command_line,
   // deleted if it already exists.
   logging::LoggingSettings settings;
   settings.logging_dest = DetermineLoggingDestination(command_line);
-  settings.log_file = log_path.value().c_str();
+  settings.log_file_path = log_path.value().c_str();
   if (!logging::InitLogging(settings)) {
     DLOG(ERROR) << "Unable to initialize logging to " << log_path.value();
     base::PostTask(FROM_HERE, {base::ThreadPool(), base::MayBlock()},
                    base::BindOnce(&RemoveSymlinkAndLog, log_path, target_path));
     return;
   }
-  chrome_logging_redirected_ = true;
+  g_chrome_logging_redirected = true;
 
   // Redirect the Network Service's logs as well if it's running out of process.
   if (content::IsOutOfProcessNetworkService()) {
     auto logging_settings = network::mojom::LoggingSettings::New();
     logging_settings->logging_dest = settings.logging_dest;
-    logging_settings->log_file = log_path;
+    const int log_file_descriptor = fileno(logging::DuplicateLogFILE());
+    if (log_file_descriptor < 0) {
+      DLOG(WARNING) << "Unable to duplicate log file handle";
+      return;
+    }
+    logging_settings->log_file_descriptor =
+        mojo::WrapPlatformFile(log_file_descriptor);
     content::GetNetworkService()->ReinitializeLogging(
         std::move(logging_settings));
   }
@@ -70,7 +79,7 @@ void RedirectChromeLogging(const base::CommandLine& command_line) {
   if (!base::SysInfo::IsRunningOnChromeOS() && !g_force_log_redirection)
     return;
 
-  if (chrome_logging_redirected_) {
+  if (g_chrome_logging_redirected) {
     // TODO: Support multiple active users. http://crbug.com/230345
     LOG(WARNING) << "NOT redirecting logging for multi-profiles case.";
     return;

chrome/chrome_cleaner/logging/scoped_logging.cc

@@ -65,7 +65,7 @@ ScopedLogging::ScopedLogging(base::FilePath::StringPieceType suffix) {
 
   logging::LoggingSettings logging_settings;
   logging_settings.logging_dest = logging::LOG_TO_FILE;
-  logging_settings.log_file = log_file_path.value().c_str();
+  logging_settings.log_file_path = log_file_path.value().c_str();
 
   bool success = logging::InitLogging(logging_settings);
   DCHECK(success);

chrome/chrome_cleaner/test/test_process_main.cc

@@ -48,7 +48,7 @@ int main(int, char**) {
       exe_file_path.ReplaceExtension(kLogFileExtension));
   logging::LoggingSettings logging_settings;
   logging_settings.logging_dest = logging::LOG_TO_FILE;
-  logging_settings.log_file = log_file_path.value().c_str();
+  logging_settings.log_file_path = log_file_path.value().c_str();
   success = logging::InitLogging(logging_settings);
   DCHECK(success);