chrome/browser/logging_chrome_unittest.cc

   1 // Copyright 2013 The Chromium Authors
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include <memory>
   6
   7 #include "base/command_line.h"
   8 #include "base/environment.h"
   9 #include "base/files/file_enumerator.h"
  10 #include "base/files/file_path.h"
  11 #include "base/files/file_util.h"
  12 #include "base/files/scoped_temp_dir.h"
  13 #include "build/chromeos_buildflags.h"
  14 #include "chrome/common/env_vars.h"
  15 #include "chrome/common/logging_chrome.h"
  16 #include "content/public/common/content_switches.h"
  17 #include "testing/gmock/include/gmock/gmock-matchers.h"
  18 #include "testing/gtest/include/gtest/gtest.h"
  19
  20 class ChromeLoggingTest : public testing::Test {
  21  public:
  22   // Stores the current value of the log file name environment
  23   // variable and sets the variable to new_value.
  24   void SaveEnvironmentVariable(const std::string& new_value) {
  25     std::unique_ptr<base::Environment> env(base::Environment::Create());
  26     if (!env->GetVar(env_vars::kLogFileName, &environment_filename_))
  27       environment_filename_ = "";
  28
  29     env->SetVar(env_vars::kLogFileName, new_value);
  30   }
  31
  32   // Restores the value of the log file nave environment variable
  33   // previously saved by SaveEnvironmentVariable().
  34   void RestoreEnvironmentVariable() {
  35     std::unique_ptr<base::Environment> env(base::Environment::Create());
  36     env->SetVar(env_vars::kLogFileName, environment_filename_);
  37   }
  38
  39   void SetLogFileFlag(const std::string& value) {
  40     cmd_line_.AppendSwitchASCII(switches::kLogFile, value);
  41   }
  42
  43   const base::CommandLine& cmd_line() { return cmd_line_; }
  44
  45  private:
  46   std::string environment_filename_;  // Saves real environment value.
  47   base::CommandLine cmd_line_ =
  48       base::CommandLine(base::CommandLine::NO_PROGRAM);
  49 };
  50
  51 // Tests the log file name getter without an environment variable.
  52 TEST_F(ChromeLoggingTest, LogFileName) {
  53   SaveEnvironmentVariable(std::string());
  54
  55   base::FilePath filename = logging::GetLogFileName(cmd_line());
  56   ASSERT_NE(base::FilePath::StringType::npos,
  57             filename.value().find(FILE_PATH_LITERAL("chrome_debug.log")));
  58 #if BUILDFLAG(IS_WIN)
  59   ASSERT_TRUE(filename.IsAbsolute());
  60 #endif  // BUILDFLAG(IS_WIN)
  61
  62   RestoreEnvironmentVariable();
  63 }
  64
  65 // Tests the log file name getter with an environment variable.
  66 #if BUILDFLAG(IS_WIN)
  67 TEST_F(ChromeLoggingTest, EnvironmentLogFileName) {
  68   SaveEnvironmentVariable("c:\\path\\test env value");
  69   base::FilePath filename = logging::GetLogFileName(cmd_line());
  70   ASSERT_NE(base::FilePath::StringType::npos,
  71             filename.value().find(FILE_PATH_LITERAL("test env value")));
  72   ASSERT_TRUE(filename.IsAbsolute());
  73   RestoreEnvironmentVariable();
  74 }
  75 #else
  76 TEST_F(ChromeLoggingTest, EnvironmentLogFileName) {
  77   SaveEnvironmentVariable("test env value");
  78   base::FilePath filename = logging::GetLogFileName(cmd_line());
  79   ASSERT_NE(base::FilePath::StringType::npos,
  80             filename.value().find(FILE_PATH_LITERAL("test env value")));
  81   RestoreEnvironmentVariable();
  82 }
  83 #endif  // BUILDFLAG(IS_WIN)
  84
  85 // Tests the log file name getter with a command-line flag.
  86 #if BUILDFLAG(IS_WIN)
  87 TEST_F(ChromeLoggingTest, FlagLogFileName) {
  88   SetLogFileFlag("c:\\path\\test flag value");
  89   base::FilePath filename = logging::GetLogFileName(cmd_line());
  90   ASSERT_NE(base::FilePath::StringType::npos,
  91             filename.value().find(FILE_PATH_LITERAL("test flag value")));
  92   ASSERT_TRUE(filename.IsAbsolute());
  93 }
  94 // Non-absolute path falls back to default.
  95 TEST_F(ChromeLoggingTest, FlagLogFileNameNonAbsolute) {
  96   SetLogFileFlag("test file value");
  97   base::FilePath filename = logging::GetLogFileName(cmd_line());
  98   ASSERT_NE(base::FilePath::StringType::npos,
  99             filename.value().find(FILE_PATH_LITERAL("chrome_debug.log")));
 100   ASSERT_TRUE(filename.IsAbsolute());
 101 }
 102 #else
 103 TEST_F(ChromeLoggingTest, FlagLogFileName) {
 104   SetLogFileFlag("test flag value");
 105   base::FilePath filename = logging::GetLogFileName(cmd_line());
 106   ASSERT_NE(base::FilePath::StringType::npos,
 107             filename.value().find(FILE_PATH_LITERAL("test flag value")));
 108 }
 109 #endif  // BUILDFLAG(IS_WIN)
 110
 111 // Tests the log file name getter with with an environment variable and a
 112 // command-line flag. The flag takes precedence.
 113 #if BUILDFLAG(IS_WIN)
 114 TEST_F(ChromeLoggingTest, EnvironmentAndFlagLogFileName) {
 115   SaveEnvironmentVariable("c:\\path\\test env value");
 116   SetLogFileFlag("d:\\path\\test flag value");
 117
 118   base::FilePath filename = logging::GetLogFileName(cmd_line());
 119   ASSERT_NE(base::FilePath::StringType::npos,
 120             filename.value().find(FILE_PATH_LITERAL("test flag value")));
 121   ASSERT_TRUE(filename.IsAbsolute());
 122   RestoreEnvironmentVariable();
 123 }
 124 #else
 125 TEST_F(ChromeLoggingTest, EnvironmentAndFlagLogFileName) {
 126   SaveEnvironmentVariable("test env value");
 127   SetLogFileFlag("test flag value");
 128
 129   base::FilePath filename = logging::GetLogFileName(cmd_line());
 130   ASSERT_NE(base::FilePath::StringType::npos,
 131             filename.value().find(FILE_PATH_LITERAL("test flag value")));
 132   RestoreEnvironmentVariable();
 133 }
 134 #endif  // BUILDFLAG(IS_WIN)
 135
 136 #if BUILDFLAG(IS_CHROMEOS_ASH)
 137 TEST_F(ChromeLoggingTest, TimestampedName) {
 138   base::FilePath path = base::FilePath(FILE_PATH_LITERAL("xy.zzy"));
 139   base::FilePath timestamped_path =
 140       logging::GenerateTimestampedName(path, base::Time::Now());
 141   EXPECT_THAT(timestamped_path.value(),
 142               ::testing::MatchesRegex("^xy_\\d+-\\d+\\.zzy$"));
 143 }
 144
 145 TEST_F(ChromeLoggingTest, SetUpSymlink) {
 146   base::ScopedTempDir temp_dir;
 147   ASSERT_TRUE(temp_dir.CreateUniqueTempDir());
 148   const base::FilePath temp_dir_path = temp_dir.GetPath();
 149   base::FilePath bare_symlink_path =
 150       temp_dir_path.AppendASCII("chrome-test-log");
 151   base::FilePath latest_symlink_path =
 152       temp_dir_path.AppendASCII("chrome-test-log.LATEST");
 153   base::FilePath previous_symlink_path =
 154       temp_dir_path.AppendASCII("chrome-test-log.PREVIOUS");
 155
 156   // Start from a legacy situation, where "chrome-test-log" is a symlink
 157   // pointing to the latest log, which has a time-stamped name from a while
 158   // ago.
 159   base::FilePath old_target_path = logging::GenerateTimestampedName(
 160       bare_symlink_path, base::Time::UnixEpoch());
 161
 162   ASSERT_TRUE(base::CreateSymbolicLink(old_target_path, bare_symlink_path));
 163
 164   // Call the testee with the new symlink path, as if starting a new session.
 165   logging::SetUpSymlinkIfNeeded(latest_symlink_path,
 166                                 /*start_new_log=*/true);
 167
 168   // We now expect:
 169   //
 170   // chrome-test-log --> chrome-test-log.LATEST
 171   // chrome-test-log.LATEST --> <new time-stamped path>
 172   // no chrome-test-log.PREVIOUS on the legacy transition.
 173   base::FilePath target_path;
 174   ASSERT_TRUE(base::ReadSymbolicLink(bare_symlink_path, &target_path));
 175   EXPECT_EQ(target_path.value(), latest_symlink_path.value());
 176
 177   base::FilePath latest_target_path;
 178   ASSERT_TRUE(base::ReadSymbolicLink(latest_symlink_path, &latest_target_path));
 179   EXPECT_NE(latest_target_path.value(), old_target_path.value());
 180   EXPECT_THAT(latest_target_path.value(),
 181               ::testing::MatchesRegex("^.*chrome-test-log_\\d+-\\d+$"));
 182
 183   // Simulate one more session cycle.
 184   logging::SetUpSymlinkIfNeeded(latest_symlink_path, /*start_new_log=*/true);
 185
 186   // We now expect:
 187   //
 188   // chrome-test-log.PREVIOUS --> <previous target of chrome-test-log.LATEST>
 189   //
 190   // We also expect that the .LATEST file is now pointing to a file with a
 191   // newer time stamp.  Unfortunately it's probably not newer enough to tell
 192   // the difference since the time stamp granularity is 1 second.
 193   ASSERT_TRUE(base::ReadSymbolicLink(previous_symlink_path, &target_path));
 194   EXPECT_EQ(target_path.value(), latest_target_path.value());
 195
 196   ASSERT_TRUE(base::ReadSymbolicLink(latest_symlink_path, &latest_target_path));
 197   EXPECT_THAT(latest_target_path.value(),
 198               ::testing::MatchesRegex("^.*chrome-test-log_\\d+-\\d+$"));
 199 }
 200
 201 // Test the case of the normal rotation.
 202 TEST_F(ChromeLoggingTest, RotateLogFiles) {
 203   constexpr char kLog1Content[] = "log#1\n";
 204   base::ScopedTempDir temp_dir;
 205   ASSERT_TRUE(temp_dir.CreateUniqueTempDir());
 206   const base::FilePath temp_dir_path = temp_dir.GetPath();
 207   base::FilePath log_path_latest = temp_dir_path.AppendASCII("chrome-test-log");
 208
 209   // Prepare the latest log file.
 210   ASSERT_TRUE(base::WriteFile(log_path_latest, kLog1Content));
 211   base::File::Info file_info;
 212   base::File(log_path_latest, base::File::FLAG_OPEN | base::File::FLAG_READ)
 213       .GetInfo(&file_info);
 214   base::Time creation_time = file_info.creation_time;
 215
 216   // Generate the log file path which is rotated to.
 217   base::FilePath expected_rotated_path =
 218       logging::GenerateTimestampedName(log_path_latest, creation_time);
 219
 220   // Check the condition before rotation.
 221   {
 222     EXPECT_TRUE(base::PathExists(log_path_latest));
 223     EXPECT_FALSE(base::PathExists(expected_rotated_path));
 224   }
 225
 226   // Simulate the rotation.
 227   ASSERT_TRUE(logging::RotateLogFile(log_path_latest));
 228
 229   // Check the conditions after rotation: the log file and the rotated log file.
 230   {
 231     EXPECT_FALSE(base::PathExists(log_path_latest));
 232     EXPECT_TRUE(base::PathExists(expected_rotated_path));
 233
 234     std::string buffer;
 235     base::ReadFileToString(expected_rotated_path, &buffer);
 236     EXPECT_EQ(buffer, kLog1Content);
 237   }
 238 }
 239
 240 // Test the case that chrome tries the rotation but there is no files.
 241 TEST_F(ChromeLoggingTest, RotateLogFilesNoFile) {
 242   base::ScopedTempDir temp_dir;
 243   ASSERT_TRUE(temp_dir.CreateUniqueTempDir());
 244   const base::FilePath temp_dir_path = temp_dir.GetPath();
 245
 246   base::FilePath log_path_latest = temp_dir_path.AppendASCII("chrome-test-log");
 247
 248   // Check the condition before rotation.
 249   {
 250     EXPECT_FALSE(base::PathExists(log_path_latest));
 251
 252     // Ensure no file in the directory.
 253     base::FileEnumerator enumerator(temp_dir_path, true,
 254                                     base::FileEnumerator::FILES);
 255     EXPECT_TRUE(enumerator.Next().empty());
 256   }
 257
 258   // Simulate the rotation.
 259   ASSERT_TRUE(logging::RotateLogFile(log_path_latest));
 260
 261   // Check the condition after rotation: nothing happens.
 262   {
 263     EXPECT_FALSE(base::PathExists(log_path_latest));
 264
 265     // Ensure still no file in the directory.
 266     base::FileEnumerator enumerator(temp_dir_path, true,
 267                                     base::FileEnumerator::FILES);
 268     EXPECT_TRUE(enumerator.Next().empty());
 269   }
 270 }
 271
 272 // Test the case that chrome tries the rotation but the target path already
 273 // exists. The logic should use the altanate target path.
 274 TEST_F(ChromeLoggingTest, RotateLogFilesExisting) {
 275   constexpr char kLatestLogContent[] = "log#1\n";
 276   constexpr char kOldLogContent[] = "log#2\n";
 277
 278   base::ScopedTempDir temp_dir;
 279   ASSERT_TRUE(temp_dir.CreateUniqueTempDir());
 280   const base::FilePath temp_dir_path = temp_dir.GetPath();
 281   base::FilePath log_path_latest = temp_dir_path.AppendASCII("chrome-test-log");
 282
 283   // Prepare the latest log file.
 284   ASSERT_TRUE(base::WriteFile(log_path_latest, kLatestLogContent));
 285   base::File::Info file_info;
 286   {
 287     base::File(log_path_latest, base::File::FLAG_OPEN | base::File::FLAG_READ)
 288         .GetInfo(&file_info);
 289   }
 290   base::Time creation_time = file_info.creation_time;
 291
 292   base::FilePath exist_log_path =
 293       logging::GenerateTimestampedName(log_path_latest, creation_time);
 294   ASSERT_TRUE(base::WriteFile(exist_log_path, kOldLogContent));
 295
 296   base::FilePath rotated_log_path = logging::GenerateTimestampedName(
 297       log_path_latest, creation_time + base::Seconds(1));
 298
 299   // Check the condition before rotation.
 300   {
 301     // The latest log file exists.
 302     EXPECT_TRUE(base::PathExists(log_path_latest));
 303     // First candidate does already exist.
 304     EXPECT_TRUE(base::PathExists(exist_log_path));
 305     // Second candidate does already exist.
 306     EXPECT_FALSE(base::PathExists(rotated_log_path));
 307   }
 308
 309   // Simulate one more session cycle.
 310   ASSERT_TRUE(logging::RotateLogFile(log_path_latest));
 311
 312   // Check the condition after rotation: the log file is renamed to the second
 313   // candidate.
 314   {
 315     EXPECT_FALSE(base::PathExists(log_path_latest));
 316     EXPECT_TRUE(base::PathExists(exist_log_path));
 317     EXPECT_TRUE(base::PathExists(rotated_log_path));
 318
 319     std::string buffer;
 320     // The first candidate is kept.
 321     base::ReadFileToString(exist_log_path, &buffer);
 322     EXPECT_EQ(buffer, kOldLogContent);
 323     // The second candidate is the previous latest log.
 324     base::ReadFileToString(rotated_log_path, &buffer);
 325     EXPECT_EQ(buffer, kLatestLogContent);
 326   }
 327 }
 328
 329 #endif  // BUILDFLAG(IS_CHROMEOS_ASH)