1 // Copyright (c) 2011 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/basictypes.h"
6 #include "base/logging.h"
7 #include "base/memory/scoped_ptr.h"
8 #include "base/message_loop.h"
9 #include "base/message_loop_proxy.h"
10 #include "base/synchronization/condition_variable.h"
11 #include "base/synchronization/lock.h"
12 #include "base/threading/platform_thread.h"
13 #include "base/time.h"
14 #include "build/build_config.h"
15 #include "chrome/browser/metrics/thread_watcher.h"
16 #include "testing/gtest/include/gtest/gtest.h"
17 #include "testing/platform_test.h"
18
19 using base::TimeDelta;
20 using base::TimeTicks;
21
22 enum State {
23 INITIALIZED, // Created ThreadWatch object.
24 ACTIVATED, // Thread watching activated.
25 SENT_PING, // Sent ping message to watched thread.
26 RECEIVED_PONG, // Received Pong message.
27 DEACTIVATED, // Thread watching de-activated.
28 };
29
30 enum WaitState {
31 UNINITIALIZED,
32 STARTED_WAITING, // Start waiting for state_ to change to expected_state.
33 STOPPED_WAITING, // Done with the waiting.
34 ALL_DONE, // Done with waiting for STOPPED_WAITING.
35 };
36
37 enum CheckResponseState {
38 UNKNOWN,
39 SUCCESSFUL, // CheckResponse was successful.
40 FAILED, // CheckResponse has failed.
41 };
42
43 // This class helps to track and manipulate thread state during tests. This
44 // class also has utility method to simulate hanging of watched thread by making
45 // the watched thread wait for a very long time by posting a task on watched
46 // thread that keeps it busy. It also has an utility method to block running of
47 // tests until ThreadWatcher object's post-condition state changes to an
48 // expected state.
49 class CustomThreadWatcher : public ThreadWatcher {
50 public:
51 base::Lock custom_lock_;
52 base::ConditionVariable state_changed_;
53 State thread_watcher_state_;
54 WaitState wait_state_;
55 CheckResponseState check_response_state_;
56 uint64 ping_sent_;
57 uint64 pong_received_;
58 uint64 success_response_;
59 uint64 failed_response_;
60 base::TimeTicks saved_ping_time_;
61 uint64 saved_ping_sequence_number_;
62
CustomThreadWatcher(const BrowserThread::ID thread_id,const std::string thread_name,const TimeDelta & sleep_time,const TimeDelta & unresponsive_time)63 CustomThreadWatcher(const BrowserThread::ID thread_id,
64 const std::string thread_name,
65 const TimeDelta& sleep_time,
66 const TimeDelta& unresponsive_time)
67 : ThreadWatcher(thread_id, thread_name, sleep_time, unresponsive_time),
68 state_changed_(&custom_lock_),
69 thread_watcher_state_(INITIALIZED),
70 wait_state_(UNINITIALIZED),
71 check_response_state_(UNKNOWN),
72 ping_sent_(0),
73 pong_received_(0),
74 success_response_(0),
75 failed_response_(0),
76 saved_ping_time_(base::TimeTicks::Now()),
77 saved_ping_sequence_number_(0) {
78 }
79
UpdateState(State new_state)80 State UpdateState(State new_state) {
81 State old_state;
82 {
83 base::AutoLock auto_lock(custom_lock_);
84 old_state = thread_watcher_state_;
85 if (old_state != DEACTIVATED)
86 thread_watcher_state_ = new_state;
87 if (new_state == SENT_PING)
88 ++ping_sent_;
89 if (new_state == RECEIVED_PONG)
90 ++pong_received_;
91 saved_ping_time_ = ping_time();
92 saved_ping_sequence_number_ = ping_sequence_number();
93 }
94 state_changed_.Broadcast();
95 return old_state;
96 }
97
UpdateWaitState(WaitState new_state)98 WaitState UpdateWaitState(WaitState new_state) {
99 WaitState old_state;
100 {
101 base::AutoLock auto_lock(custom_lock_);
102 old_state = wait_state_;
103 wait_state_ = new_state;
104 }
105 state_changed_.Broadcast();
106 return old_state;
107 }
108
ActivateThreadWatching()109 void ActivateThreadWatching() {
110 State old_state = UpdateState(ACTIVATED);
111 EXPECT_EQ(old_state, INITIALIZED);
112 ThreadWatcher::ActivateThreadWatching();
113 }
114
DeActivateThreadWatching()115 void DeActivateThreadWatching() {
116 State old_state = UpdateState(DEACTIVATED);
117 EXPECT_TRUE(old_state == ACTIVATED || old_state == SENT_PING ||
118 old_state == RECEIVED_PONG);
119 ThreadWatcher::DeActivateThreadWatching();
120 }
121
PostPingMessage()122 void PostPingMessage() {
123 State old_state = UpdateState(SENT_PING);
124 EXPECT_TRUE(old_state == ACTIVATED || old_state == RECEIVED_PONG);
125 ThreadWatcher::PostPingMessage();
126 }
127
OnPongMessage(uint64 ping_sequence_number)128 void OnPongMessage(uint64 ping_sequence_number) {
129 State old_state = UpdateState(RECEIVED_PONG);
130 EXPECT_TRUE(old_state == SENT_PING || old_state == DEACTIVATED);
131 ThreadWatcher::OnPongMessage(ping_sequence_number);
132 }
133
OnCheckResponsiveness(uint64 ping_sequence_number)134 bool OnCheckResponsiveness(uint64 ping_sequence_number) {
135 bool responsive =
136 ThreadWatcher::OnCheckResponsiveness(ping_sequence_number);
137 {
138 base::AutoLock auto_lock(custom_lock_);
139 if (responsive) {
140 ++success_response_;
141 check_response_state_ = SUCCESSFUL;
142 } else {
143 ++failed_response_;
144 check_response_state_ = FAILED;
145 }
146 }
147 // Broadcast to indicate we have checked responsiveness of the thread that
148 // is watched.
149 state_changed_.Broadcast();
150 return responsive;
151 }
152
WaitForWaitStateChange(TimeDelta wait_time,WaitState expected_state)153 void WaitForWaitStateChange(TimeDelta wait_time, WaitState expected_state) {
154 DCHECK(!WatchDogThread::CurrentlyOnWatchDogThread());
155 TimeTicks end_time = TimeTicks::Now() + wait_time;
156 {
157 base::AutoLock auto_lock(custom_lock_);
158 while (wait_state_ != expected_state && TimeTicks::Now() < end_time)
159 state_changed_.TimedWait(end_time - TimeTicks::Now());
160 }
161 }
162
VeryLongMethod(TimeDelta wait_time)163 void VeryLongMethod(TimeDelta wait_time) {
164 DCHECK(!WatchDogThread::CurrentlyOnWatchDogThread());
165 WaitForWaitStateChange(wait_time, STOPPED_WAITING);
166 UpdateWaitState(ALL_DONE);
167 }
168
WaitForStateChange(const TimeDelta & wait_time,State expected_state)169 State WaitForStateChange(const TimeDelta& wait_time, State expected_state) {
170 DCHECK(!WatchDogThread::CurrentlyOnWatchDogThread());
171 UpdateWaitState(STARTED_WAITING);
172
173 State exit_state;
174 // Keep the thread that is running the tests waiting until ThreadWatcher
175 // object's state changes to the expected_state or until wait_time elapses.
176 for (int i = 0; i < 3; ++i) {
177 TimeTicks end_time = TimeTicks::Now() + wait_time;
178 {
179 base::AutoLock auto_lock(custom_lock_);
180 while (thread_watcher_state_ != expected_state &&
181 TimeTicks::Now() < end_time) {
182 TimeDelta state_change_wait_time = end_time - TimeTicks::Now();
183 state_changed_.TimedWait(state_change_wait_time);
184 }
185 // Capture the thread_watcher_state_ before it changes and return it
186 // to the caller.
187 exit_state = thread_watcher_state_;
188 if (exit_state == expected_state)
189 break;
190 }
191 }
192 UpdateWaitState(STOPPED_WAITING);
193 return exit_state;
194 }
195
WaitForCheckResponse(const TimeDelta & wait_time,CheckResponseState expected_state)196 CheckResponseState WaitForCheckResponse(const TimeDelta& wait_time,
197 CheckResponseState expected_state) {
198 DCHECK(!WatchDogThread::CurrentlyOnWatchDogThread());
199 UpdateWaitState(STARTED_WAITING);
200
201 CheckResponseState exit_state;
202 // Keep the thread that is running the tests waiting until ThreadWatcher
203 // object's check_response_state_ changes to the expected_state or until
204 // wait_time elapses.
205 for (int i = 0; i < 3; ++i) {
206 TimeTicks end_time = TimeTicks::Now() + wait_time;
207 {
208 base::AutoLock auto_lock(custom_lock_);
209 while (check_response_state_ != expected_state &&
210 TimeTicks::Now() < end_time) {
211 TimeDelta state_change_wait_time = end_time - TimeTicks::Now();
212 state_changed_.TimedWait(state_change_wait_time);
213 }
214 // Capture the check_response_state_ before it changes and return it
215 // to the caller.
216 exit_state = check_response_state_;
217 if (exit_state == expected_state)
218 break;
219 }
220 }
221 UpdateWaitState(STOPPED_WAITING);
222 return exit_state;
223 }
224 };
225
226 DISABLE_RUNNABLE_METHOD_REFCOUNT(CustomThreadWatcher);
227
228 class ThreadWatcherTest : public ::testing::Test {
229 public:
230 static const TimeDelta kSleepTime;
231 static const TimeDelta kUnresponsiveTime;
232 static const BrowserThread::ID io_thread_id;
233 static const std::string io_thread_name;
234 static const BrowserThread::ID webkit_thread_id;
235 static const std::string webkit_thread_name;
236 CustomThreadWatcher* io_watcher_;
237 CustomThreadWatcher* webkit_watcher_;
238
ThreadWatcherTest()239 ThreadWatcherTest() {
240 webkit_thread_.reset(new BrowserThread(BrowserThread::WEBKIT));
241 io_thread_.reset(new BrowserThread(BrowserThread::IO));
242 watchdog_thread_.reset(new WatchDogThread());
243 webkit_thread_->Start();
244 io_thread_->Start();
245 watchdog_thread_->Start();
246
247 // Setup the registry for thread watchers.
248 thread_watcher_list_ = new ThreadWatcherList();
249
250 // Create thread watcher object for the IO thread.
251 io_watcher_ = new CustomThreadWatcher(io_thread_id, io_thread_name,
252 kSleepTime, kUnresponsiveTime);
253
254 // Create thread watcher object for the WEBKIT thread.
255 webkit_watcher_ = new CustomThreadWatcher(
256 webkit_thread_id, webkit_thread_name, kSleepTime, kUnresponsiveTime);
257 }
258
~ThreadWatcherTest()259 ~ThreadWatcherTest() {
260 ThreadWatcherList::StopWatchingAll();
261 io_watcher_ = NULL;
262 webkit_watcher_ = NULL;
263 io_thread_.reset();
264 webkit_thread_.reset();
265 watchdog_thread_.reset();
266 delete thread_watcher_list_;
267 }
268
269 private:
270 scoped_ptr<BrowserThread> webkit_thread_;
271 scoped_ptr<BrowserThread> io_thread_;
272 scoped_ptr<WatchDogThread> watchdog_thread_;
273 ThreadWatcherList* thread_watcher_list_;
274 };
275
276 // Define static constants.
277 const TimeDelta ThreadWatcherTest::kSleepTime =
278 TimeDelta::FromMilliseconds(50);
279 const TimeDelta ThreadWatcherTest::kUnresponsiveTime =
280 TimeDelta::FromMilliseconds(500);
281 const BrowserThread::ID ThreadWatcherTest::io_thread_id = BrowserThread::IO;
282 const std::string ThreadWatcherTest::io_thread_name = "IO";
283 const BrowserThread::ID ThreadWatcherTest::webkit_thread_id =
284 BrowserThread::WEBKIT;
285 const std::string ThreadWatcherTest::webkit_thread_name = "WEBKIT";
286
287 // Test registration. When thread_watcher_list_ goes out of scope after
288 // TearDown, all thread watcher objects will be deleted.
TEST_F(ThreadWatcherTest,Registration)289 TEST_F(ThreadWatcherTest, Registration) {
290 EXPECT_EQ(io_watcher_, ThreadWatcherList::Find(io_thread_id));
291 EXPECT_EQ(webkit_watcher_, ThreadWatcherList::Find(webkit_thread_id));
292
293 // Check ThreadWatcher object has all correct parameters.
294 EXPECT_EQ(io_thread_id, io_watcher_->thread_id());
295 EXPECT_EQ(io_thread_name, io_watcher_->thread_name());
296 EXPECT_EQ(kSleepTime, io_watcher_->sleep_time());
297 EXPECT_EQ(kUnresponsiveTime, io_watcher_->unresponsive_time());
298 EXPECT_FALSE(io_watcher_->active());
299
300 // Check ThreadWatcher object of watched WEBKIT thread has correct data.
301 EXPECT_EQ(webkit_thread_id, webkit_watcher_->thread_id());
302 EXPECT_EQ(webkit_thread_name, webkit_watcher_->thread_name());
303 EXPECT_EQ(kSleepTime, webkit_watcher_->sleep_time());
304 EXPECT_EQ(kUnresponsiveTime, webkit_watcher_->unresponsive_time());
305 EXPECT_FALSE(webkit_watcher_->active());
306 }
307
308 // Test ActivateThreadWatching and DeActivateThreadWatching of IO thread. This
309 // method also checks that pong message was sent by the watched thread and pong
310 // message was received by the WatchDogThread. It also checks that
311 // OnCheckResponsiveness has verified the ping-pong mechanism and the watched
312 // thread is not hung.
TEST_F(ThreadWatcherTest,ThreadResponding)313 TEST_F(ThreadWatcherTest, ThreadResponding) {
314 TimeTicks time_before_ping = TimeTicks::Now();
315 // Activate watching IO thread.
316 WatchDogThread::PostTask(
317 FROM_HERE,
318 NewRunnableMethod(io_watcher_, &ThreadWatcher::ActivateThreadWatching));
319
320 // Activate would have started ping/pong messaging. Expect atleast one
321 // ping/pong messaging sequence to happen.
322 io_watcher_->WaitForStateChange(kSleepTime + TimeDelta::FromMinutes(1),
323 RECEIVED_PONG);
324 EXPECT_GT(io_watcher_->ping_sent_, static_cast<uint64>(0));
325 EXPECT_GT(io_watcher_->pong_received_, static_cast<uint64>(0));
326 EXPECT_TRUE(io_watcher_->active());
327 EXPECT_GE(io_watcher_->saved_ping_time_, time_before_ping);
328 EXPECT_GE(io_watcher_->saved_ping_sequence_number_, static_cast<uint64>(0));
329
330 // Verify watched thread is responding with ping/pong messaging.
331 io_watcher_->WaitForCheckResponse(
332 kUnresponsiveTime + TimeDelta::FromMinutes(1), SUCCESSFUL);
333 EXPECT_GT(io_watcher_->success_response_, static_cast<uint64>(0));
334 EXPECT_EQ(io_watcher_->failed_response_, static_cast<uint64>(0));
335
336 // DeActivate thread watching for shutdown.
337 WatchDogThread::PostTask(
338 FROM_HERE,
339 NewRunnableMethod(io_watcher_, &ThreadWatcher::DeActivateThreadWatching));
340 }
341
342 // This test posts a task on watched thread that takes very long time (this is
343 // to simulate hanging of watched thread). It then checks for
344 // OnCheckResponsiveness raising an alert (OnCheckResponsiveness returns false
345 // if the watched thread is not responding).
TEST_F(ThreadWatcherTest,ThreadNotResponding)346 TEST_F(ThreadWatcherTest, ThreadNotResponding) {
347 // Simulate hanging of watched thread by making the watched thread wait for a
348 // very long time by posting a task on watched thread that keeps it busy.
349 BrowserThread::PostTask(
350 io_thread_id,
351 FROM_HERE,
352 NewRunnableMethod(
353 io_watcher_,
354 &CustomThreadWatcher::VeryLongMethod,
355 kUnresponsiveTime * 10));
356
357 // Activate thread watching.
358 WatchDogThread::PostTask(
359 FROM_HERE,
360 NewRunnableMethod(io_watcher_, &ThreadWatcher::ActivateThreadWatching));
361
362 // Verify watched thread is not responding for ping messages.
363 io_watcher_->WaitForCheckResponse(
364 kUnresponsiveTime + TimeDelta::FromMinutes(1), FAILED);
365 EXPECT_EQ(io_watcher_->success_response_, static_cast<uint64>(0));
366 EXPECT_GT(io_watcher_->failed_response_, static_cast<uint64>(0));
367
368 // DeActivate thread watching for shutdown.
369 WatchDogThread::PostTask(
370 FROM_HERE,
371 NewRunnableMethod(io_watcher_, &ThreadWatcher::DeActivateThreadWatching));
372
373 // Wait for the io_watcher_'s VeryLongMethod to finish.
374 io_watcher_->WaitForWaitStateChange(kUnresponsiveTime * 10, ALL_DONE);
375 }
376
377 // Test watching of multiple threads with all threads not responding.
TEST_F(ThreadWatcherTest,MultipleThreadsResponding)378 TEST_F(ThreadWatcherTest, MultipleThreadsResponding) {
379 // Check for WEBKIT thread to perform ping/pong messaging.
380 WatchDogThread::PostTask(
381 FROM_HERE,
382 NewRunnableMethod(
383 webkit_watcher_, &ThreadWatcher::ActivateThreadWatching));
384
385 // Check for IO thread to perform ping/pong messaging.
386 WatchDogThread::PostTask(
387 FROM_HERE,
388 NewRunnableMethod(io_watcher_, &ThreadWatcher::ActivateThreadWatching));
389
390 // Verify WEBKIT thread is responding with ping/pong messaging.
391 webkit_watcher_->WaitForCheckResponse(
392 kUnresponsiveTime + TimeDelta::FromMinutes(1), SUCCESSFUL);
393 EXPECT_GT(webkit_watcher_->ping_sent_, static_cast<uint64>(0));
394 EXPECT_GT(webkit_watcher_->pong_received_, static_cast<uint64>(0));
395 EXPECT_GE(webkit_watcher_->ping_sequence_number_, static_cast<uint64>(0));
396 EXPECT_GT(webkit_watcher_->success_response_, static_cast<uint64>(0));
397 EXPECT_EQ(webkit_watcher_->failed_response_, static_cast<uint64>(0));
398
399 // Verify IO thread is responding with ping/pong messaging.
400 io_watcher_->WaitForCheckResponse(
401 kUnresponsiveTime + TimeDelta::FromMinutes(1), SUCCESSFUL);
402 EXPECT_GT(io_watcher_->ping_sent_, static_cast<uint64>(0));
403 EXPECT_GT(io_watcher_->pong_received_, static_cast<uint64>(0));
404 EXPECT_GE(io_watcher_->ping_sequence_number_, static_cast<uint64>(0));
405 EXPECT_GT(io_watcher_->success_response_, static_cast<uint64>(0));
406 EXPECT_EQ(io_watcher_->failed_response_, static_cast<uint64>(0));
407
408 // DeActivate thread watching for shutdown.
409 WatchDogThread::PostTask(
410 FROM_HERE,
411 NewRunnableMethod(io_watcher_, &ThreadWatcher::DeActivateThreadWatching));
412
413 WatchDogThread::PostTask(
414 FROM_HERE,
415 NewRunnableMethod(
416 webkit_watcher_, &ThreadWatcher::DeActivateThreadWatching));
417 }
418
419 // Test watching of multiple threads with one of the threads not responding.
TEST_F(ThreadWatcherTest,MultipleThreadsNotResponding)420 TEST_F(ThreadWatcherTest, MultipleThreadsNotResponding) {
421 // Simulate hanging of watched thread by making the watched thread wait for a
422 // very long time by posting a task on watched thread that keeps it busy.
423 BrowserThread::PostTask(
424 io_thread_id,
425 FROM_HERE,
426 NewRunnableMethod(
427 io_watcher_,
428 &CustomThreadWatcher::VeryLongMethod,
429 kUnresponsiveTime * 10));
430
431 // Activate watching of WEBKIT thread.
432 WatchDogThread::PostTask(
433 FROM_HERE,
434 NewRunnableMethod(
435 webkit_watcher_, &ThreadWatcher::ActivateThreadWatching));
436
437 // Activate watching of IO thread.
438 WatchDogThread::PostTask(
439 FROM_HERE,
440 NewRunnableMethod(io_watcher_, &ThreadWatcher::ActivateThreadWatching));
441
442 // Verify WEBKIT thread is responding with ping/pong messaging.
443 webkit_watcher_->WaitForCheckResponse(
444 kUnresponsiveTime + TimeDelta::FromMinutes(1), SUCCESSFUL);
445 EXPECT_GT(webkit_watcher_->success_response_, static_cast<uint64>(0));
446 EXPECT_EQ(webkit_watcher_->failed_response_, static_cast<uint64>(0));
447
448 // Verify IO thread is not responding for ping messages.
449 io_watcher_->WaitForCheckResponse(
450 kUnresponsiveTime + TimeDelta::FromMinutes(1), FAILED);
451 EXPECT_EQ(io_watcher_->success_response_, static_cast<uint64>(0));
452 EXPECT_GT(io_watcher_->failed_response_, static_cast<uint64>(0));
453
454 // DeActivate thread watching for shutdown.
455 WatchDogThread::PostTask(
456 FROM_HERE,
457 NewRunnableMethod(io_watcher_, &ThreadWatcher::DeActivateThreadWatching));
458 WatchDogThread::PostTask(
459 FROM_HERE,
460 NewRunnableMethod(
461 webkit_watcher_, &ThreadWatcher::DeActivateThreadWatching));
462
463 // Wait for the io_watcher_'s VeryLongMethod to finish.
464 io_watcher_->WaitForWaitStateChange(kUnresponsiveTime * 10, ALL_DONE);
465 }
466