logging_chrome: remove log file extension in the right place

An earlier commit needlessly ruined GenerateTimestampedName()
making it indiscriminately remove extensions.  The extension-chopping
code is being put in the right place (at the caller site).

BUG=chromium:781363
TEST=none

Change-Id: Ic0edf8e082ce9af34b6679bec179e76e8f4797dc
Reviewed-on: https://chromium-review.googlesource.com/838242
Commit-Queue: Luigi Semenzato <semenzato@chromium.org>
Reviewed-by: Lei Zhang <thestig@chromium.org>
Cr-Commit-Position: refs/heads/master@{#532113}

base/files/scoped_temp_dir.h

@@ -5,11 +5,13 @@
 #ifndef BASE_FILES_SCOPED_TEMP_DIR_H_
 #define BASE_FILES_SCOPED_TEMP_DIR_H_
 
-// An object representing a temporary / scratch directory that should be cleaned
-// up (recursively) when this object goes out of scope.  Note that since
-// deletion occurs during the destructor, no further error handling is possible
-// if the directory fails to be deleted.  As a result, deletion is not
-// guaranteed by this class.
+// An object representing a temporary / scratch directory that should be
+// cleaned up (recursively) when this object goes out of scope.  Since deletion
+// occurs during the destructor, no further error handling is possible if the
+// directory fails to be deleted.  As a result, deletion is not guaranteed by
+// this class.  (However note that, whenever possible, by default
+// CreateUniqueTempDir creates the directory in a location that is
+// automatically cleaned up on reboot, or at other appropriate times.)
 //
 // Multiple calls to the methods which establish a temporary directory
 // (CreateUniqueTempDir, CreateUniqueTempDirUnderPath, and Set) must have

chrome/browser/logging_chrome_unittest.cc

@@ -7,9 +7,12 @@
 #include "base/command_line.h"
 #include "base/environment.h"
 #include "base/files/file_path.h"
+#include "base/files/file_util.h"
+#include "base/files/scoped_temp_dir.h"
 #include "chrome/common/env_vars.h"
 #include "chrome/common/logging_chrome.h"
 #include "content/public/common/content_switches.h"
+#include "testing/gmock/include/gmock/gmock-matchers.h"
 #include "testing/gtest/include/gtest/gtest.h"
 
 class ChromeLoggingTest : public testing::Test {
@@ -86,3 +89,70 @@ TEST_F(ChromeLoggingTest, EnvironmentAndFlagLogFileName) {
 
   RestoreEnvironmentVariable();
 }
+
+#if defined(OS_CHROMEOS)
+TEST_F(ChromeLoggingTest, TimestampedName) {
+  base::FilePath path = base::FilePath(FILE_PATH_LITERAL("xy.zzy"));
+  base::FilePath timestamped_path =
+      logging::GenerateTimestampedName(path, base::Time::Now());
+  EXPECT_THAT(timestamped_path.value(),
+              ::testing::MatchesRegex("^xy_\\d+-\\d+\\.zzy$"));
+}
+
+TEST_F(ChromeLoggingTest, SetUpSymlink) {
+  base::ScopedTempDir temp_dir;
+  ASSERT_TRUE(temp_dir.CreateUniqueTempDir());
+  const base::FilePath temp_dir_path = temp_dir.GetPath();
+  base::FilePath bare_symlink_path =
+      temp_dir_path.Append(FILE_PATH_LITERAL("chrome-test-log"));
+  base::FilePath latest_symlink_path =
+      temp_dir_path.Append(FILE_PATH_LITERAL("chrome-test-log.LATEST"));
+  base::FilePath previous_symlink_path =
+      temp_dir_path.Append(FILE_PATH_LITERAL("chrome-test-log.PREVIOUS"));
+
+  // Start from a legacy situation, where "chrome-test-log" is a symlink
+  // pointing to the latest log, which has a time-stamped name from a while
+  // ago.
+  base::FilePath old_target_path = logging::GenerateTimestampedName(
+      bare_symlink_path, base::Time::UnixEpoch());
+
+  ASSERT_TRUE(base::CreateSymbolicLink(old_target_path, bare_symlink_path));
+
+  // Call the testee with the new symlink path, as if starting a new session.
+  logging::SetUpSymlinkIfNeeded(latest_symlink_path,
+                                /*start_new_log=*/true);
+
+  // We now expect:
+  //
+  // chrome-test-log --> chrome-test-log.LATEST
+  // chrome-test-log.LATEST --> <new time-stamped path>
+  // no chrome-test-log.PREVIOUS on the legacy transition.
+  base::FilePath target_path;
+  ASSERT_TRUE(base::ReadSymbolicLink(bare_symlink_path, &target_path));
+  EXPECT_EQ(target_path.value(), latest_symlink_path.value());
+
+  base::FilePath latest_target_path;
+  ASSERT_TRUE(base::ReadSymbolicLink(latest_symlink_path, &latest_target_path));
+  EXPECT_NE(latest_target_path.value(), old_target_path.value());
+  EXPECT_THAT(latest_target_path.value(),
+              ::testing::MatchesRegex("^.*chrome-test-log_\\d+-\\d+$"));
+
+  // Simulate one more session cycle.
+  logging::SetUpSymlinkIfNeeded(latest_symlink_path, /*start_new_log=*/true);
+
+  // We now expect:
+  //
+  // chrome-test-log.PREVIOUS --> <previous target of chrome-test-log.LATEST>
+  //
+  // We also expect that the .LATEST file is now pointing to a file with a
+  // newer time stamp.  Unfortunately it's probably not newer enough to tell
+  // the difference since the time stamp granularity is 1 second.
+  ASSERT_TRUE(base::ReadSymbolicLink(previous_symlink_path, &target_path));
+  EXPECT_EQ(target_path.value(), latest_target_path.value());
+
+  ASSERT_TRUE(base::ReadSymbolicLink(latest_symlink_path, &latest_target_path));
+  EXPECT_THAT(latest_target_path.value(),
+              ::testing::MatchesRegex("^.*chrome-test-log_\\d+-\\d+$"));
+}
+
+#endif  // defined(OS_CHROMEOS)

chrome/common/logging_chrome.cc

@@ -167,14 +167,15 @@ base::FilePath SetUpSymlinkIfNeeded(const base::FilePath& symlink_path,
   if (symlink_path.Extension() == ".LATEST") {
     base::FilePath extensionless_path = symlink_path.ReplaceExtension("");
     base::FilePath target_path;
+    bool extensionless_symlink_exists =
+        base::ReadSymbolicLink(extensionless_path, &target_path);
 
-    base::ReadSymbolicLink(extensionless_path, &target_path);
     if (target_path != symlink_path) {
       // No link, or wrong link.  Clean up.  This should happen only once in
       // each log directory after the OS version update, but some of those
       // directories may not be accessed for a long time, so this code needs to
       // stay in forever :/
-      if (base::PathExists(extensionless_path) &&
+      if (extensionless_symlink_exists &&
           !base::DeleteFile(extensionless_path, false)) {
         DPLOG(WARNING) << "Cannot delete " << extensionless_path.value();
       }
@@ -190,29 +191,32 @@ base::FilePath SetUpSymlinkIfNeeded(const base::FilePath& symlink_path,
   //
   // If starting a new log, then rename the old symlink as
   // symlink_path.PREVIOUS and make a new symlink to a fresh log file.
+
+  // Check for existence of the symlink.
   base::FilePath target_path;
-  bool symlink_exists = base::PathExists(symlink_path);
-  if (new_log || !symlink_exists) {
-    target_path = GenerateTimestampedName(symlink_path, base::Time::Now());
-
-    if (symlink_exists) {
-      base::FilePath previous_symlink_path =
-          symlink_path.ReplaceExtension(".PREVIOUS");
-      // Rename symlink to .PREVIOUS.  This nukes an existing symlink just like
-      // the rename(2) syscall does.
-      if (!base::ReplaceFile(symlink_path, previous_symlink_path, nullptr)) {
-        DPLOG(WARNING) << "Cannot rename " << symlink_path.value() << " to "
-                       << previous_symlink_path.value();
-      }
-    }
-    // If all went well, the symlink no longer exists.  Recreate it.
-    if (!base::CreateSymbolicLink(target_path, symlink_path)) {
-      DPLOG(ERROR) << "Unable to create symlink " << symlink_path.value()
-                   << " pointing at " << target_path.value();
+  bool symlink_exists = base::ReadSymbolicLink(symlink_path, &target_path);
+
+  if (symlink_exists && !new_log)
+    return target_path;
+
+  // Remove any extension before time-stamping.
+  target_path = GenerateTimestampedName(symlink_path.RemoveExtension(),
+                                        base::Time::Now());
+
+  if (symlink_exists) {
+    base::FilePath previous_symlink_path =
+        symlink_path.ReplaceExtension(".PREVIOUS");
+    // Rename symlink to .PREVIOUS.  This nukes an existing symlink just like
+    // the rename(2) syscall does.
+    if (!base::ReplaceFile(symlink_path, previous_symlink_path, nullptr)) {
+      DPLOG(WARNING) << "Cannot rename " << symlink_path.value() << " to "
+                     << previous_symlink_path.value();
     }
-  } else {
-    if (!base::ReadSymbolicLink(symlink_path, &target_path))
-      DPLOG(ERROR) << "Unable to read symlink " << symlink_path.value();
+  }
+  // If all went well, the symlink no longer exists.  Recreate it.
+  if (!base::CreateSymbolicLink(target_path, symlink_path)) {
+    DPLOG(ERROR) << "Unable to create symlink " << symlink_path.value()
+                 << " pointing at " << target_path.value();
   }
   return target_path;
 }
@@ -256,7 +260,7 @@ base::FilePath GetSessionLogFile(const base::CommandLine& command_line) {
       .Append(GetLogFileName(command_line).BaseName());
 }
 
-#endif  // OS_CHROMEOS
+#endif  // defined(OS_CHROMEOS)
 
 void InitChromeLogging(const base::CommandLine& command_line,
                        OldFileDeletionState delete_old_log_file) {
@@ -291,7 +295,7 @@ void InitChromeLogging(const base::CommandLine& command_line,
     // the link, it shouldn't remove the old file in the logging code,
     // since that will remove the newly created link instead.
     delete_old_log_file = APPEND_TO_OLD_LOG_FILE;
-#endif
+#endif  // defined(OS_CHROMEOS)
   } else {
     log_locking_state = DONT_LOCK_LOG_FILE;
   }
@@ -311,13 +315,13 @@ void InitChromeLogging(const base::CommandLine& command_line,
     chrome_logging_failed_ = true;
     return;
   }
-#else
+#else   // defined(OS_CHROMEOS)
   if (!success) {
     DPLOG(ERROR) << "Unable to initialize logging to " << log_path.value();
     chrome_logging_failed_ = true;
     return;
   }
-#endif
+#endif  // defined(OS_CHROMEOS)
 
   // We call running in unattended mode "headless", and allow headless mode to
   // be configured either by the Environment Variable or by the Command Line
@@ -417,11 +421,6 @@ base::FilePath GenerateTimestampedName(const base::FilePath& base_path,
                                        base::Time timestamp) {
   base::Time::Exploded time_deets;
   timestamp.LocalExplode(&time_deets);
-  base::FilePath new_path = base_path;
-  // Assume that the base_path is "chrome.LATEST", and remove the extension.
-  // Ideally we would also check the value of base_path, but we cannot reliably
-  // log anything here, and aborting seems too harsh a choice.
-  new_path = new_path.ReplaceExtension("");
   std::string suffix = base::StringPrintf("_%02d%02d%02d-%02d%02d%02d",
                                           time_deets.year,
                                           time_deets.month,
@@ -429,7 +428,7 @@ base::FilePath GenerateTimestampedName(const base::FilePath& base_path,
                                           time_deets.hour,
                                           time_deets.minute,
                                           time_deets.second);
-  return new_path.InsertBeforeExtensionASCII(suffix);
+  return base_path.InsertBeforeExtensionASCII(suffix);
 }
 #endif  // defined(OS_CHROMEOS)
 

chrome/common/logging_chrome.h

@@ -66,7 +66,7 @@ bool DialogsAreSuppressed();
 // "_yymmdd-hhmmss".
 base::FilePath GenerateTimestampedName(const base::FilePath& base_path,
                                        base::Time timestamp);
-#endif
+#endif  // OS_CHROMEOS
 }  // namespace logging
 
 #endif  // CHROME_COMMON_LOGGING_CHROME_H_