1 // Copyright 2013 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 #include "base/cancelable_callback.h" 6 #include "base/command_line.h" 7 #include "base/memory/scoped_ptr.h" 8 #include "base/run_loop.h" 9 #include "base/strings/stringprintf.h" 10 #include "base/synchronization/waitable_event.h" 11 #include "base/test/simple_test_clock.h" 12 #include "chrome/browser/extensions/activity_log/activity_log.h" 13 #include "chrome/browser/extensions/activity_log/counting_policy.h" 14 #include "chrome/browser/extensions/extension_service.h" 15 #include "chrome/browser/extensions/test_extension_system.h" 16 #include "chrome/common/chrome_constants.h" 17 #include "chrome/common/chrome_switches.h" 18 #include "chrome/common/extensions/extension_builder.h" 19 #include "chrome/test/base/chrome_render_view_host_test_harness.h" 20 #include "chrome/test/base/testing_profile.h" 21 #include "content/public/test/test_browser_thread_bundle.h" 22 #include "sql/statement.h" 23 #include "testing/gtest/include/gtest/gtest.h" 24 25 #if defined(OS_CHROMEOS) 26 #include "chrome/browser/chromeos/login/user_manager.h" 27 #include "chrome/browser/chromeos/settings/cros_settings.h" 28 #include "chrome/browser/chromeos/settings/device_settings_service.h" 29 #endif 30 31 namespace extensions { 32 33 class CountingPolicyTest : public testing::Test { 34 public: 35 CountingPolicyTest() 36 : thread_bundle_(content::TestBrowserThreadBundle::IO_MAINLOOP), 37 saved_cmdline_(CommandLine::NO_PROGRAM) { 38 #if defined OS_CHROMEOS 39 test_user_manager_.reset(new chromeos::ScopedTestUserManager()); 40 #endif 41 CommandLine command_line(CommandLine::NO_PROGRAM); 42 saved_cmdline_ = *CommandLine::ForCurrentProcess(); 43 profile_.reset(new TestingProfile()); 44 CommandLine::ForCurrentProcess()->AppendSwitch( 45 switches::kEnableExtensionActivityLogging); 46 CommandLine::ForCurrentProcess()->AppendSwitch( 47 switches::kEnableExtensionActivityLogTesting); 48 extension_service_ = static_cast<TestExtensionSystem*>( 49 ExtensionSystem::Get(profile_.get()))->CreateExtensionService 50 (&command_line, base::FilePath(), false); 51 } 52 53 virtual ~CountingPolicyTest() { 54 #if defined OS_CHROMEOS 55 test_user_manager_.reset(); 56 #endif 57 base::RunLoop().RunUntilIdle(); 58 profile_.reset(NULL); 59 base::RunLoop().RunUntilIdle(); 60 // Restore the original command line and undo the affects of SetUp(). 61 *CommandLine::ForCurrentProcess() = saved_cmdline_; 62 } 63 64 // A helper function to call ReadData on a policy object and wait for the 65 // results to be processed. 66 void CheckReadData( 67 ActivityLogPolicy* policy, 68 const std::string& extension_id, 69 const int day, 70 const base::Callback<void(scoped_ptr<Action::ActionVector>)>& checker) { 71 // Submit a request to the policy to read back some data, and call the 72 // checker function when results are available. This will happen on the 73 // database thread. 74 policy->ReadData( 75 extension_id, 76 day, 77 base::Bind(&CountingPolicyTest::CheckWrapper, 78 checker, 79 base::MessageLoop::current()->QuitClosure())); 80 81 // Set up a timeout that will trigger after 5 seconds; if we haven't 82 // received any results by then assume that the test is broken. 83 base::CancelableClosure timeout( 84 base::Bind(&CountingPolicyTest::TimeoutCallback)); 85 base::MessageLoop::current()->PostDelayedTask( 86 FROM_HERE, timeout.callback(), base::TimeDelta::FromSeconds(5)); 87 88 // Wait for results; either the checker or the timeout callbacks should 89 // cause the main loop to exit. 90 base::MessageLoop::current()->Run(); 91 92 timeout.Cancel(); 93 } 94 95 static void CheckWrapper( 96 const base::Callback<void(scoped_ptr<Action::ActionVector>)>& checker, 97 const base::Closure& done, 98 scoped_ptr<Action::ActionVector> results) { 99 checker.Run(results.Pass()); 100 done.Run(); 101 } 102 103 static void TimeoutCallback() { 104 base::MessageLoop::current()->QuitWhenIdle(); 105 FAIL() << "Policy test timed out waiting for results"; 106 } 107 108 static void Arguments_Stripped(scoped_ptr<Action::ActionVector> i) { 109 scoped_refptr<Action> last = i->front(); 110 std::string args = 111 "ID=odlameecjipmbmbejkplpemijjgpljce CATEGORY=api_call " 112 "API=extension.connect ARGS=[\"hello\",\"world\"] COUNT=1"; 113 ASSERT_EQ(args, last->PrintForDebug()); 114 } 115 116 static void Arguments_GetTodaysActions( 117 scoped_ptr<Action::ActionVector> actions) { 118 std::string api_stripped_print = 119 "ID=punky CATEGORY=api_call API=brewster COUNT=2"; 120 std::string api_print = 121 "ID=punky CATEGORY=api_call API=extension.sendMessage " 122 "ARGS=[\"not\",\"stripped\"] COUNT=1"; 123 std::string dom_print = 124 "ID=punky CATEGORY=dom_access API=lets ARGS=[\"vamoose\"] " 125 "PAGE_URL=http://www.google.com/ COUNT=1"; 126 ASSERT_EQ(3, static_cast<int>(actions->size())); 127 ASSERT_EQ(dom_print, actions->at(0)->PrintForDebug()); 128 ASSERT_EQ(api_print, actions->at(1)->PrintForDebug()); 129 ASSERT_EQ(api_stripped_print, actions->at(2)->PrintForDebug()); 130 } 131 132 static void Arguments_GetOlderActions( 133 scoped_ptr<Action::ActionVector> actions) { 134 std::string api_print = 135 "ID=punky CATEGORY=api_call API=brewster COUNT=1"; 136 std::string dom_print = 137 "ID=punky CATEGORY=dom_access API=lets ARGS=[\"vamoose\"] " 138 "PAGE_URL=http://www.google.com/ COUNT=1"; 139 ASSERT_EQ(2, static_cast<int>(actions->size())); 140 ASSERT_EQ(dom_print, actions->at(0)->PrintForDebug()); 141 ASSERT_EQ(api_print, actions->at(1)->PrintForDebug()); 142 } 143 144 static void Arguments_CheckMergeCount( 145 int count, 146 scoped_ptr<Action::ActionVector> actions) { 147 std::string api_print = base::StringPrintf( 148 "ID=punky CATEGORY=api_call API=brewster COUNT=%d", count); 149 if (count > 0) { 150 ASSERT_EQ(1u, actions->size()); 151 ASSERT_EQ(api_print, actions->at(0)->PrintForDebug()); 152 } else { 153 ASSERT_EQ(0u, actions->size()); 154 } 155 } 156 157 protected: 158 ExtensionService* extension_service_; 159 scoped_ptr<TestingProfile> profile_; 160 content::TestBrowserThreadBundle thread_bundle_; 161 // Used to preserve a copy of the original command line. 162 // The test framework will do this itself as well. However, by then, 163 // it is too late to call ActivityLog::RecomputeLoggingIsEnabled() in 164 // TearDown(). 165 CommandLine saved_cmdline_; 166 167 #if defined OS_CHROMEOS 168 chromeos::ScopedTestDeviceSettingsService test_device_settings_service_; 169 chromeos::ScopedTestCrosSettings test_cros_settings_; 170 scoped_ptr<chromeos::ScopedTestUserManager> test_user_manager_; 171 #endif 172 }; 173 174 TEST_F(CountingPolicyTest, Construct) { 175 ActivityLogPolicy* policy = new CountingPolicy(profile_.get()); 176 scoped_refptr<const Extension> extension = 177 ExtensionBuilder() 178 .SetManifest(DictionaryBuilder() 179 .Set("name", "Test extension") 180 .Set("version", "1.0.0") 181 .Set("manifest_version", 2)) 182 .Build(); 183 extension_service_->AddExtension(extension.get()); 184 scoped_ptr<base::ListValue> args(new base::ListValue()); 185 scoped_refptr<Action> action = new Action(extension->id(), 186 base::Time::Now(), 187 Action::ACTION_API_CALL, 188 "tabs.testMethod"); 189 action->set_args(args.Pass()); 190 policy->ProcessAction(action); 191 policy->Close(); 192 } 193 194 TEST_F(CountingPolicyTest, LogWithStrippedArguments) { 195 ActivityLogPolicy* policy = new CountingPolicy(profile_.get()); 196 scoped_refptr<const Extension> extension = 197 ExtensionBuilder() 198 .SetManifest(DictionaryBuilder() 199 .Set("name", "Test extension") 200 .Set("version", "1.0.0") 201 .Set("manifest_version", 2)) 202 .Build(); 203 extension_service_->AddExtension(extension.get()); 204 205 scoped_ptr<base::ListValue> args(new base::ListValue()); 206 args->Set(0, new base::StringValue("hello")); 207 args->Set(1, new base::StringValue("world")); 208 scoped_refptr<Action> action = new Action(extension->id(), 209 base::Time::Now(), 210 Action::ACTION_API_CALL, 211 "extension.connect"); 212 action->set_args(args.Pass()); 213 214 policy->ProcessAction(action); 215 CheckReadData(policy, 216 extension->id(), 217 0, 218 base::Bind(&CountingPolicyTest::Arguments_Stripped)); 219 policy->Close(); 220 } 221 222 TEST_F(CountingPolicyTest, GetTodaysActions) { 223 CountingPolicy* policy = new CountingPolicy(profile_.get()); 224 // Disable row expiration for this test by setting a time before any actions 225 // we generate. 226 policy->set_retention_time(base::TimeDelta::FromDays(14)); 227 228 // Use a mock clock to ensure that events are not recorded on the wrong day 229 // when the test is run close to local midnight. Note: Ownership is passed 230 // to the policy, but we still keep a pointer locally. The policy will take 231 // care of destruction; this is safe since the policy outlives all our 232 // accesses to the mock clock. 233 base::SimpleTestClock* mock_clock = new base::SimpleTestClock(); 234 mock_clock->SetNow(base::Time::Now().LocalMidnight() + 235 base::TimeDelta::FromHours(12)); 236 policy->SetClockForTesting(scoped_ptr<base::Clock>(mock_clock)); 237 238 // Record some actions 239 scoped_refptr<Action> action = 240 new Action("punky", 241 mock_clock->Now() - base::TimeDelta::FromMinutes(40), 242 Action::ACTION_API_CALL, 243 "brewster"); 244 action->mutable_args()->AppendString("woof"); 245 policy->ProcessAction(action); 246 247 action = new Action("punky", 248 mock_clock->Now() - base::TimeDelta::FromMinutes(30), 249 Action::ACTION_API_CALL, 250 "brewster"); 251 action->mutable_args()->AppendString("meow"); 252 policy->ProcessAction(action); 253 254 action = new Action("punky", 255 mock_clock->Now() - base::TimeDelta::FromMinutes(20), 256 Action::ACTION_API_CALL, 257 "extension.sendMessage"); 258 action->mutable_args()->AppendString("not"); 259 action->mutable_args()->AppendString("stripped"); 260 policy->ProcessAction(action); 261 262 action = 263 new Action("punky", mock_clock->Now(), Action::ACTION_DOM_ACCESS, "lets"); 264 action->mutable_args()->AppendString("vamoose"); 265 action->set_page_url(GURL("http://www.google.com")); 266 policy->ProcessAction(action); 267 268 action = new Action( 269 "scoobydoo", mock_clock->Now(), Action::ACTION_DOM_ACCESS, "lets"); 270 action->mutable_args()->AppendString("vamoose"); 271 action->set_page_url(GURL("http://www.google.com")); 272 policy->ProcessAction(action); 273 274 CheckReadData( 275 policy, 276 "punky", 277 0, 278 base::Bind(&CountingPolicyTest::Arguments_GetTodaysActions)); 279 policy->Close(); 280 } 281 282 // Check that we can read back less recent actions in the db. 283 TEST_F(CountingPolicyTest, GetOlderActions) { 284 CountingPolicy* policy = new CountingPolicy(profile_.get()); 285 policy->set_retention_time(base::TimeDelta::FromDays(14)); 286 287 // Use a mock clock to ensure that events are not recorded on the wrong day 288 // when the test is run close to local midnight. 289 base::SimpleTestClock* mock_clock = new base::SimpleTestClock(); 290 mock_clock->SetNow(base::Time::Now().LocalMidnight() + 291 base::TimeDelta::FromHours(12)); 292 policy->SetClockForTesting(scoped_ptr<base::Clock>(mock_clock)); 293 294 // Record some actions 295 scoped_refptr<Action> action = 296 new Action("punky", 297 mock_clock->Now() - base::TimeDelta::FromDays(3) - 298 base::TimeDelta::FromMinutes(40), 299 Action::ACTION_API_CALL, 300 "brewster"); 301 action->mutable_args()->AppendString("woof"); 302 policy->ProcessAction(action); 303 304 action = new Action("punky", 305 mock_clock->Now() - base::TimeDelta::FromDays(3), 306 Action::ACTION_DOM_ACCESS, 307 "lets"); 308 action->mutable_args()->AppendString("vamoose"); 309 action->set_page_url(GURL("http://www.google.com")); 310 policy->ProcessAction(action); 311 312 action = new Action("punky", 313 mock_clock->Now(), 314 Action::ACTION_DOM_ACCESS, 315 "lets"); 316 action->mutable_args()->AppendString("too new"); 317 action->set_page_url(GURL("http://www.google.com")); 318 policy->ProcessAction(action); 319 320 action = new Action("punky", 321 mock_clock->Now() - base::TimeDelta::FromDays(7), 322 Action::ACTION_DOM_ACCESS, 323 "lets"); 324 action->mutable_args()->AppendString("too old"); 325 action->set_page_url(GURL("http://www.google.com")); 326 policy->ProcessAction(action); 327 328 CheckReadData( 329 policy, 330 "punky", 331 3, 332 base::Bind(&CountingPolicyTest::Arguments_GetOlderActions)); 333 334 policy->Close(); 335 } 336 337 // Check that merging of actions only occurs within the same day, not across 338 // days, and that old data can be expired from the database. 339 TEST_F(CountingPolicyTest, MergingAndExpiring) { 340 CountingPolicy* policy = new CountingPolicy(profile_.get()); 341 // Initially disable expiration by setting a retention time before any 342 // actions we generate. 343 policy->set_retention_time(base::TimeDelta::FromDays(14)); 344 345 // Use a mock clock to ensure that events are not recorded on the wrong day 346 // when the test is run close to local midnight. 347 base::SimpleTestClock* mock_clock = new base::SimpleTestClock(); 348 mock_clock->SetNow(base::Time::Now().LocalMidnight() + 349 base::TimeDelta::FromHours(12)); 350 policy->SetClockForTesting(scoped_ptr<base::Clock>(mock_clock)); 351 352 // The first two actions should be merged; the last one is on a separate day 353 // and should not be. 354 scoped_refptr<Action> action = 355 new Action("punky", 356 mock_clock->Now() - base::TimeDelta::FromDays(3) - 357 base::TimeDelta::FromMinutes(40), 358 Action::ACTION_API_CALL, 359 "brewster"); 360 policy->ProcessAction(action); 361 362 action = new Action("punky", 363 mock_clock->Now() - base::TimeDelta::FromDays(3) - 364 base::TimeDelta::FromMinutes(20), 365 Action::ACTION_API_CALL, 366 "brewster"); 367 policy->ProcessAction(action); 368 369 action = new Action("punky", 370 mock_clock->Now() - base::TimeDelta::FromDays(2) - 371 base::TimeDelta::FromMinutes(20), 372 Action::ACTION_API_CALL, 373 "brewster"); 374 policy->ProcessAction(action); 375 376 CheckReadData(policy, 377 "punky", 378 3, 379 base::Bind(&CountingPolicyTest::Arguments_CheckMergeCount, 2)); 380 CheckReadData(policy, 381 "punky", 382 2, 383 base::Bind(&CountingPolicyTest::Arguments_CheckMergeCount, 1)); 384 385 // Clean actions before midnight two days ago. Force expiration to run by 386 // clearing last_database_cleaning_time_ and submitting a new action. 387 policy->set_retention_time(base::TimeDelta::FromDays(2)); 388 policy->last_database_cleaning_time_ = base::Time(); 389 action = new Action("punky", 390 mock_clock->Now(), 391 Action::ACTION_API_CALL, 392 "brewster"); 393 policy->ProcessAction(action); 394 395 CheckReadData(policy, 396 "punky", 397 3, 398 base::Bind(&CountingPolicyTest::Arguments_CheckMergeCount, 0)); 399 CheckReadData(policy, 400 "punky", 401 2, 402 base::Bind(&CountingPolicyTest::Arguments_CheckMergeCount, 1)); 403 404 policy->Close(); 405 } 406 407 } // namespace extensions 408
