1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. 2 // Use of this source code is governed by a BSD-style license that can be 3 // found in the LICENSE file. 4 // 5 // This file provides reliablity tests which run for ChromeFrame. 6 // 7 // Usage: 8 // <reliability test exe> --list=file --startline=start --endline=end [...] 9 // Upon invocation, it visits each of the URLs on line numbers between start 10 // and end, inclusive, stored in the input file. The line number starts from 1. 11 // 12 // Optional Switches: 13 // --iterations=num: goes through the list of URLs constructed in usage 2 or 3 14 // num times. 15 // --memoryusage: prints out memory usage when visiting each page. 16 // --logfile=filepath: saves the visit log to the specified path. 17 // --timeout=seconds: time out as specified in seconds during each 18 // page load. 19 // --nopagedown: won't simulate page down key presses after page load. 20 // --noclearprofile: do not clear profile dir before firing up each time. 21 // --savedebuglog: save Chrome, V8, and test debug log for each page loaded. 22 #include <fstream> 23 #include <ostream> 24 25 #include "base/command_line.h" 26 #include "base/file_util.h" 27 #include "base/file_version_info.h" 28 #include "base/files/file_enumerator.h" 29 #include "base/files/file_path.h" 30 #include "base/i18n/time_formatting.h" 31 #include "base/path_service.h" 32 #include "base/prefs/json_pref_store.h" 33 #include "base/prefs/pref_registry_simple.h" 34 #include "base/prefs/pref_service.h" 35 #include "base/prefs/pref_value_store.h" 36 #include "base/strings/string_number_conversions.h" 37 #include "base/strings/string_util.h" 38 #include "base/strings/utf_string_conversions.h" 39 #include "base/test/test_file_util.h" 40 #include "base/time/time.h" 41 #include "chrome/browser/prefs/pref_service_mock_builder.h" 42 #include "chrome/common/automation_messages.h" 43 #include "chrome/common/chrome_constants.h" 44 #include "chrome/common/chrome_paths.h" 45 #include "chrome/common/chrome_paths_internal.h" 46 #include "chrome/common/chrome_switches.h" 47 #include "chrome/common/logging_chrome.h" 48 #include "chrome/common/net/url_fixer_upper.h" 49 #include "chrome/common/pref_names.h" 50 #include "chrome/test/automation/automation_proxy.h" 51 #include "chrome/test/automation/browser_proxy.h" 52 #include "chrome/test/automation/tab_proxy.h" 53 #include "chrome/test/automation/window_proxy.h" 54 #include "chrome/test/ui/ui_test.h" 55 #include "chrome_frame/test/chrome_frame_test_utils.h" 56 #include "chrome_frame/test/ie_event_sink.h" 57 #include "chrome_frame/test/reliability/page_load_test.h" 58 #include "chrome_frame/utils.h" 59 #include "content/public/browser/browser_thread.h" 60 #include "content/public/test/test_browser_thread.h" 61 #include "net/base/net_util.h" 62 #include "testing/gmock/include/gmock/gmock.h" 63 #include "testing/gtest/include/gtest/gtest.h" 64 65 using testing::StrCaseEq; 66 using testing::StrCaseNe; 67 68 namespace { 69 70 // See comments at the beginning of the file for the definition of switches. 71 const char kListSwitch[] = "list"; 72 const char kStartIndexSwitch[] = "startline"; 73 const char kEndIndexSwitch[] = "endline"; 74 const char kIterationSwitch[] = "iterations"; 75 const char kContinuousLoadSwitch[] = "continuousload"; 76 const char kMemoryUsageSwitch[] = "memoryusage"; 77 const char kLogFileSwitch[] = "logfile"; 78 const char kTimeoutSwitch[] = "timeout"; 79 const char kNoPageDownSwitch[] = "nopagedown"; 80 const char kNoClearProfileSwitch[] = "noclearprofile"; 81 const char kSaveDebugLogSwitch[] = "savedebuglog"; 82 83 // These are copied from v8 definitions as we cannot include them. 84 const char kV8LogFileSwitch[] = "logfile"; 85 const char kV8LogFileDefaultName[] = "v8.log"; 86 87 // String name of local chrome dll for looking up file information. 88 const wchar_t kChromeDll[] = L"chrome.dll"; 89 90 base::FilePath g_url_file_path; 91 int32 g_start_index = 1; 92 int32 g_end_index = kint32max; 93 int32 g_iterations = 1; 94 bool g_memory_usage = false; 95 bool g_page_down = true; 96 bool g_clear_profile = true; 97 std::string g_end_url; 98 base::FilePath g_log_file_path; 99 bool g_save_debug_log = false; 100 base::FilePath g_chrome_log_path; 101 base::FilePath g_v8_log_path; 102 base::FilePath g_test_log_path; 103 bool g_stand_alone = false; 104 105 const int kUrlNavigationTimeoutSeconds = 20; 106 int g_timeout_seconds = kUrlNavigationTimeoutSeconds; 107 108 // Mocks document complete and load events. 109 class MockLoadListener : public chrome_frame_test::IEEventListener { 110 public: 111 MOCK_METHOD1(OnDocumentComplete, void (const wchar_t* url)); // NOLINT 112 MOCK_METHOD1(OnLoad, void (const wchar_t* url)); // NOLINT 113 MOCK_METHOD0(OnQuit, void ()); // NOLINT 114 115 private: 116 virtual void OnDocumentComplete(IDispatch* dispatch, VARIANT* url) { 117 if (url->bstrVal) 118 OnDocumentComplete(url->bstrVal); 119 } 120 }; 121 122 ACTION_P(QuitIE, event_sink) { 123 EXPECT_HRESULT_SUCCEEDED(event_sink->CloseWebBrowser()); 124 } 125 126 class PageLoadTest : public testing::Test { 127 public: 128 enum NavigationResult { 129 NAVIGATION_ERROR = 0, 130 NAVIGATION_SUCCESS, 131 }; 132 133 typedef struct { 134 // These are results from the test automation that drives Chrome 135 NavigationResult result; 136 int crash_dump_count; 137 // These are stability metrics recorded by Chrome itself 138 bool browser_clean_exit; 139 int browser_launch_count; 140 int page_load_count; 141 int browser_crash_count; 142 int renderer_crash_count; 143 int plugin_crash_count; 144 } NavigationMetrics; 145 146 PageLoadTest() {} 147 148 // Accept URL as std::string here because the url may also act as a test id 149 // and needs to be logged in its original format even if invalid. 150 void NavigateToURLLogResult(const std::string& url_string, 151 std::ofstream& log_file, 152 NavigationMetrics* metrics_output) { 153 GURL url(url_string); 154 NavigationMetrics metrics = {NAVIGATION_ERROR}; 155 std::ofstream test_log; 156 157 // Create a test log. 158 g_test_log_path = base::FilePath(FILE_PATH_LITERAL("test_log.log")); 159 test_log.open(g_test_log_path.value().c_str()); 160 161 // Check file version info for chrome dll. 162 scoped_ptr<FileVersionInfo> file_info; 163 #if defined(OS_WIN) 164 file_info.reset( 165 FileVersionInfo::CreateFileVersionInfo(base::FilePath(kChromeDll))); 166 #elif defined(OS_LINUX) || defined(OS_MACOSX) 167 // TODO(fmeawad): the version retrieved here belongs to the test module and 168 // not the chrome binary, need to be changed to chrome binary instead. 169 file_info.reset(FileVersionInfo::CreateFileVersionInfoForCurrentModule()); 170 #endif // !defined(OS_WIN) 171 std::wstring last_change = file_info->last_change(); 172 test_log << "Last Change: "; 173 test_log << last_change << std::endl; 174 175 176 // Log timestamp for test start. 177 base::Time time_now = base::Time::Now(); 178 double time_start = time_now.ToDoubleT(); 179 test_log << "Test Start: "; 180 test_log << base::TimeFormatFriendlyDateAndTime(time_now) << std::endl; 181 182 HRESULT hr = E_FAIL; 183 184 chrome_frame_test::TimedMsgLoop message_loop; 185 186 // Launch IE. 187 base::win::ScopedComPtr<IWebBrowser2> web_browser2; 188 hr = chrome_frame_test::LaunchIEAsComServer(web_browser2.Receive()); 189 EXPECT_HRESULT_SUCCEEDED(hr); 190 EXPECT_TRUE(web_browser2.get() != NULL); 191 web_browser2->put_Visible(VARIANT_TRUE); 192 193 // Log Browser Launched time. 194 time_now = base::Time::Now(); 195 test_log << "browser_launched_seconds="; 196 test_log << (time_now.ToDoubleT() - time_start) << std::endl; 197 198 bool is_chrome_frame_navigation = 199 StartsWith(UTF8ToWide(url.spec()), kChromeProtocolPrefix, true); 200 201 CComObjectStack<chrome_frame_test::IEEventSink> ie_event_sink; 202 MockLoadListener load_listener; 203 // Disregard any interstitial about:blank loads. 204 EXPECT_CALL(load_listener, OnDocumentComplete(StrCaseEq(L"about:blank"))) 205 .Times(testing::AnyNumber()); 206 207 // Note that we can't compare the loaded url directly with the given url 208 // because the page may have redirected us to a different page, e.g. 209 // www.google.com -> www.google.ca. 210 if (is_chrome_frame_navigation) { 211 EXPECT_CALL(load_listener, OnDocumentComplete(testing::_)); 212 EXPECT_CALL(load_listener, OnLoad(testing::_)) 213 .WillOnce(QuitIE(&ie_event_sink)); 214 } else { 215 EXPECT_CALL(load_listener, OnDocumentComplete(StrCaseNe(L"about:blank"))) 216 .WillOnce(QuitIE(&ie_event_sink)); 217 } 218 EXPECT_CALL(load_listener, OnQuit()).WillOnce(QUIT_LOOP(message_loop)); 219 220 // Attach the sink and navigate. 221 ie_event_sink.set_listener(&load_listener); 222 ie_event_sink.Attach(web_browser2); 223 hr = ie_event_sink.Navigate(UTF8ToWide(url.spec())); 224 if (SUCCEEDED(hr)) { 225 message_loop.RunFor(base::TimeDelta::FromSeconds(g_timeout_seconds)); 226 if (!message_loop.WasTimedOut()) 227 metrics.result = NAVIGATION_SUCCESS; 228 } 229 230 // Log navigate complete time. 231 time_now = base::Time::Now(); 232 test_log << "navigate_complete_seconds="; 233 test_log << (time_now.ToDoubleT() - time_start) << std::endl; 234 235 // Close IE. 236 ie_event_sink.set_listener(NULL); 237 ie_event_sink.Uninitialize(); 238 chrome_frame_test::CloseAllIEWindows(); 239 240 // Log end of test time. 241 time_now = base::Time::Now(); 242 test_log << "total_duration_seconds="; 243 test_log << (time_now.ToDoubleT() - time_start) << std::endl; 244 245 // Get navigation result and metrics, and optionally write to the log file 246 // provided. The log format is: 247 // <url> <navigation_result> <browser_crash_count> <renderer_crash_count> 248 // <plugin_crash_count> <crash_dump_count> [chrome_log=<path> 249 // v8_log=<path>] crash_dump=<path> 250 if (log_file.is_open()) { 251 log_file << url_string; 252 switch (metrics.result) { 253 case NAVIGATION_ERROR: 254 log_file << " error"; 255 break; 256 case NAVIGATION_SUCCESS: 257 log_file << " success"; 258 break; 259 default: 260 break; 261 } 262 } 263 264 // Get stability metrics recorded by Chrome itself. 265 if (is_chrome_frame_navigation) { 266 GetStabilityMetrics(&metrics); 267 } 268 269 if (log_file.is_open()) { 270 log_file << " " << metrics.browser_crash_count \ 271 // The renderer crash count is flaky due to 1183283. 272 // Ignore the count since we also catch crash by 273 // crash_dump_count. 274 << " " << 0 \ 275 << " " << metrics.plugin_crash_count \ 276 << " " << metrics.crash_dump_count; 277 } 278 279 // Close test log. 280 test_log.close(); 281 282 if (log_file.is_open() && g_save_debug_log) 283 SaveDebugLogs(log_file); 284 285 // Log revision information for Chrome build under test. 286 log_file << " " << "revision=" << last_change; 287 288 // Get crash dumps. 289 LogOrDeleteNewCrashDumps(log_file, &metrics); 290 291 if (log_file.is_open()) { 292 log_file << std::endl; 293 } 294 295 if (metrics_output) { 296 *metrics_output = metrics; 297 } 298 } 299 300 void NavigateThroughURLList(std::ofstream& log_file) { 301 std::ifstream file(g_url_file_path.value().c_str()); 302 ASSERT_TRUE(file.is_open()); 303 304 // We navigate to URLs in the following order. 305 // CF -> CF -> host -> CF -> CF -> host. 306 for (int line_index = 1; 307 line_index <= g_end_index && !file.eof(); 308 ++line_index) { 309 std::string url_str; 310 std::getline(file, url_str); 311 312 if (file.fail()) { 313 break; 314 } 315 316 // Every 3rd URL goes into the host browser. 317 if (line_index % 3 != 0) { 318 std::string actual_url; 319 actual_url = WideToUTF8(kChromeProtocolPrefix); 320 actual_url += url_str; 321 url_str = actual_url; 322 } 323 324 if (g_start_index <= line_index) { 325 NavigateToURLLogResult(url_str, log_file, NULL); 326 } 327 } 328 329 file.close(); 330 } 331 332 protected: 333 virtual void SetUp() { 334 // Initialize crash_dumps_dir_path_. 335 PathService::Get(chrome::DIR_CRASH_DUMPS, &crash_dumps_dir_path_); 336 base::FileEnumerator enumerator(crash_dumps_dir_path_, 337 false, // not recursive 338 base::FileEnumerator::FILES); 339 for (base::FilePath path = enumerator.Next(); !path.value().empty(); 340 path = enumerator.Next()) { 341 if (path.MatchesExtension(FILE_PATH_LITERAL(".dmp"))) 342 crash_dumps_[path.BaseName()] = true; 343 } 344 345 if (g_clear_profile) { 346 base::FilePath user_data_dir; 347 chrome::GetChromeFrameUserDataDirectory(&user_data_dir); 348 ASSERT_TRUE(file_util::DieFileDie(user_data_dir, true)); 349 } 350 351 SetConfigBool(kChromeFrameHeadlessMode, true); 352 SetConfigBool(kAllowUnsafeURLs, true); 353 } 354 355 virtual void TearDown() { 356 DeleteConfigValue(kChromeFrameHeadlessMode); 357 DeleteConfigValue(kAllowUnsafeURLs); 358 } 359 360 base::FilePath ConstructSavedDebugLogPath(const base::FilePath& debug_log_path, 361 int index) { 362 std::string suffix("_"); 363 suffix.append(base::IntToString(index)); 364 return debug_log_path.InsertBeforeExtensionASCII(suffix); 365 } 366 367 void SaveDebugLog(const base::FilePath& log_path, const std::wstring& log_id, 368 std::ofstream& log_file, int index) { 369 if (!log_path.empty()) { 370 base::FilePath saved_log_file_path = 371 ConstructSavedDebugLogPath(log_path, index); 372 if (base::Move(log_path, saved_log_file_path)) { 373 log_file << " " << log_id << "=" << saved_log_file_path.value(); 374 } 375 } 376 } 377 378 // Rename the chrome and v8 debug log files if existing, and save the file 379 // paths in the log_file provided. 380 void SaveDebugLogs(std::ofstream& log_file) { 381 static int url_count = 1; 382 SaveDebugLog(g_chrome_log_path, L"chrome_log", log_file, url_count); 383 SaveDebugLog(g_v8_log_path, L"v8_log", log_file, url_count); 384 SaveDebugLog(g_test_log_path, L"test_log", log_file, url_count); 385 url_count++; 386 } 387 388 // If a log_file is provided, log the crash dump with the given path; 389 // otherwise, delete the crash dump file. 390 void LogOrDeleteCrashDump(std::ofstream& log_file, 391 base::FilePath crash_dump_file_name) { 392 base::FilePath crash_dump_file_path(crash_dumps_dir_path_); 393 crash_dump_file_path = crash_dump_file_path.Append(crash_dump_file_name); 394 base::FilePath crash_text_file_path = 395 crash_dump_file_path.ReplaceExtension(FILE_PATH_LITERAL("txt")); 396 397 if (log_file.is_open()) { 398 crash_dumps_[crash_dump_file_name] = true; 399 log_file << " crash_dump=" << crash_dump_file_path.value().c_str(); 400 } else { 401 ASSERT_TRUE(file_util::DieFileDie( 402 crash_dump_file_path, false)); 403 ASSERT_TRUE(file_util::DieFileDie( 404 crash_text_file_path, false)); 405 } 406 } 407 408 // Check whether there are new .dmp files. Additionally, write 409 // " crash_dump=<full path name of the .dmp file>" 410 // to log_file. 411 void LogOrDeleteNewCrashDumps(std::ofstream& log_file, 412 NavigationMetrics* metrics) { 413 int num_dumps = 0; 414 415 base::FileEnumerator enumerator(crash_dumps_dir_path_, 416 false, // not recursive 417 base::FileEnumerator::FILES); 418 for (base::FilePath path = enumerator.Next(); !path.value().empty(); 419 path = enumerator.Next()) { 420 if (path.MatchesExtension(FILE_PATH_LITERAL(".dmp")) && 421 !crash_dumps_[path.BaseName()]) { 422 LogOrDeleteCrashDump(log_file, path.BaseName()); 423 num_dumps++; 424 } 425 } 426 if (metrics) 427 metrics->crash_dump_count = num_dumps; 428 } 429 430 // Get a PrefService whose contents correspond to the Local State file 431 // that was saved by the app as it closed. The caller takes ownership of the 432 // returned PrefService object. 433 PrefService* GetLocalState(PrefRegistry* registry) { 434 base::FilePath path; 435 chrome::GetChromeFrameUserDataDirectory(&path); 436 PrefServiceMockBuilder builder; 437 builder.WithUserFilePrefs( 438 path, 439 JsonPrefStore::GetTaskRunnerForFile( 440 path, content::BrowserThread::GetBlockingPool())); 441 return builder.Create(registry); 442 } 443 444 void GetStabilityMetrics(NavigationMetrics* metrics) { 445 if (!metrics) 446 return; 447 scoped_refptr<PrefRegistrySimple> registry = new PrefRegistrySimple(); 448 registry->RegisterBooleanPref(prefs::kStabilityExitedCleanly, false); 449 registry->RegisterIntegerPref(prefs::kStabilityLaunchCount, -1); 450 registry->RegisterIntegerPref(prefs::kStabilityPageLoadCount, -1); 451 registry->RegisterIntegerPref(prefs::kStabilityCrashCount, 0); 452 registry->RegisterIntegerPref(prefs::kStabilityRendererCrashCount, 0); 453 454 scoped_ptr<PrefService> local_state(GetLocalState(registry)); 455 if (!local_state.get()) 456 return; 457 458 metrics->browser_clean_exit = 459 local_state->GetBoolean(prefs::kStabilityExitedCleanly); 460 metrics->browser_launch_count = 461 local_state->GetInteger(prefs::kStabilityLaunchCount); 462 metrics->page_load_count = 463 local_state->GetInteger(prefs::kStabilityPageLoadCount); 464 metrics->browser_crash_count = 465 local_state->GetInteger(prefs::kStabilityCrashCount); 466 metrics->renderer_crash_count = 467 local_state->GetInteger(prefs::kStabilityRendererCrashCount); 468 // TODO(huanr) 469 metrics->plugin_crash_count = 0; 470 471 if (!metrics->browser_clean_exit) 472 metrics->browser_crash_count++; 473 } 474 475 base::FilePath GetSampleDataDir() { 476 base::FilePath test_dir; 477 PathService::Get(chrome::DIR_TEST_DATA, &test_dir); 478 test_dir = test_dir.AppendASCII("reliability"); 479 test_dir = test_dir.AppendASCII("sample_pages"); 480 return test_dir; 481 } 482 483 // The pathname of Chrome's crash dumps directory. 484 base::FilePath crash_dumps_dir_path_; 485 486 // The set of all the crash dumps we have seen. Each crash generates a 487 // .dmp and a .txt file in the crash dumps directory. We only store the 488 // .dmp files in this set. 489 // 490 // The set is implemented as a std::map. The key is the file name, and 491 // the value is false (the file is not in the set) or true (the file is 492 // in the set). The initial value for any key in std::map is 0 (false), 493 // which in this case means a new file is not in the set initially, 494 // exactly the semantics we want. 495 std::map<base::FilePath, bool> crash_dumps_; 496 }; 497 498 TEST_F(PageLoadTest, IEFullTabMode_Reliability) { 499 std::ofstream log_file; 500 501 if (!g_log_file_path.empty()) { 502 log_file.open(g_log_file_path.value().c_str()); 503 } 504 505 EXPECT_FALSE(g_url_file_path.empty()); 506 507 for (int k = 0; k < g_iterations; ++k) { 508 NavigateThroughURLList(log_file); 509 } 510 511 log_file.close(); 512 } 513 514 } // namespace 515 516 namespace { 517 void ReportHandler(const std::string& str) { 518 // Ignore report events. 519 } 520 } 521 522 void SetPageRange(const CommandLine& parsed_command_line) { 523 // If calling into this function, we are running as a standalone program. 524 g_stand_alone = true; 525 526 // Since we use --enable-dcheck for reliability tests, suppress the error 527 // dialog in the test process. 528 logging::SetLogReportHandler(ReportHandler); 529 530 if (parsed_command_line.HasSwitch(kStartIndexSwitch)) { 531 ASSERT_TRUE( 532 base::StringToInt(parsed_command_line.GetSwitchValueASCII( 533 kStartIndexSwitch), 534 &g_start_index)); 535 ASSERT_GT(g_start_index, 0); 536 } 537 538 if (parsed_command_line.HasSwitch(kEndIndexSwitch)) { 539 ASSERT_TRUE( 540 base::StringToInt(parsed_command_line.GetSwitchValueASCII( 541 kEndIndexSwitch), 542 &g_end_index)); 543 ASSERT_GT(g_end_index, 0); 544 } 545 546 ASSERT_TRUE(g_end_index >= g_start_index); 547 548 if (parsed_command_line.HasSwitch(kListSwitch)) 549 g_url_file_path = parsed_command_line.GetSwitchValuePath(kListSwitch); 550 551 if (parsed_command_line.HasSwitch(kIterationSwitch)) { 552 ASSERT_TRUE( 553 base::StringToInt(parsed_command_line.GetSwitchValueASCII( 554 kIterationSwitch), 555 &g_iterations)); 556 ASSERT_GT(g_iterations, 0); 557 } 558 559 if (parsed_command_line.HasSwitch(kMemoryUsageSwitch)) 560 g_memory_usage = true; 561 562 if (parsed_command_line.HasSwitch(kLogFileSwitch)) 563 g_log_file_path = parsed_command_line.GetSwitchValuePath(kLogFileSwitch); 564 565 if (parsed_command_line.HasSwitch(kTimeoutSwitch)) { 566 ASSERT_TRUE( 567 base::StringToInt(parsed_command_line.GetSwitchValueASCII( 568 kTimeoutSwitch), 569 &g_timeout_seconds)); 570 ASSERT_GT(g_timeout_seconds, 0); 571 } 572 573 if (parsed_command_line.HasSwitch(kNoPageDownSwitch)) 574 g_page_down = false; 575 576 if (parsed_command_line.HasSwitch(kNoClearProfileSwitch)) 577 g_clear_profile = false; 578 579 if (parsed_command_line.HasSwitch(kSaveDebugLogSwitch)) { 580 g_save_debug_log = true; 581 g_chrome_log_path = logging::GetLogFileName(); 582 // We won't get v8 log unless --no-sandbox is specified. 583 if (parsed_command_line.HasSwitch(switches::kNoSandbox)) { 584 PathService::Get(base::DIR_CURRENT, &g_v8_log_path); 585 g_v8_log_path = g_v8_log_path.AppendASCII(kV8LogFileDefaultName); 586 // The command line switch may override the default v8 log path. 587 if (parsed_command_line.HasSwitch(switches::kJavaScriptFlags)) { 588 CommandLine v8_command_line( 589 parsed_command_line.GetSwitchValuePath(switches::kJavaScriptFlags)); 590 if (v8_command_line.HasSwitch(kV8LogFileSwitch)) { 591 g_v8_log_path = base::MakeAbsoluteFilePath( 592 v8_command_line.GetSwitchValuePath(kV8LogFileSwitch)); 593 } 594 } 595 } 596 } 597 } 598