OLD | NEW |
1 // Copyright (c) 2012 The Chromium Authors. All rights reserved. | 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 | 2 // Use of this source code is governed by a BSD-style license that can be |
3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
4 | 4 |
5 #include "build/build_config.h" | 5 #include "ipc/ipc_perftest_support.h" |
6 | |
7 #include <algorithm> | |
8 #include <string> | |
9 | |
10 #include "base/basictypes.h" | |
11 #include "base/logging.h" | |
12 #include "base/memory/scoped_ptr.h" | |
13 #include "base/pickle.h" | |
14 #include "base/strings/stringprintf.h" | |
15 #include "base/test/perf_time_logger.h" | |
16 #include "base/test/test_io_thread.h" | |
17 #include "base/threading/thread.h" | |
18 #include "base/time/time.h" | |
19 #include "ipc/ipc_channel.h" | |
20 #include "ipc/ipc_channel_proxy.h" | |
21 #include "ipc/ipc_descriptors.h" | |
22 #include "ipc/ipc_message_utils.h" | |
23 #include "ipc/ipc_sender.h" | |
24 #include "ipc/ipc_test_base.h" | |
25 | 6 |
26 namespace { | 7 namespace { |
27 | 8 |
28 // This test times the roundtrip IPC message cycle. | 9 // This test times the roundtrip IPC message cycle. |
29 // | 10 // |
30 // TODO(brettw): Make this test run by default. | 11 // TODO(brettw): Make this test run by default. |
31 | 12 |
32 class IPCChannelPerfTest : public IPCTestBase { | 13 class IPCChannelPerfTest : public IPC::test::IPCChannelPerfTestBase { |
33 }; | |
34 | |
35 // This class simply collects stats about abstract "events" (each of which has a | |
36 // start time and an end time). | |
37 class EventTimeTracker { | |
38 public: | |
39 explicit EventTimeTracker(const char* name) | |
40 : name_(name), | |
41 count_(0) { | |
42 } | |
43 | |
44 void AddEvent(const base::TimeTicks& start, const base::TimeTicks& end) { | |
45 DCHECK(end >= start); | |
46 count_++; | |
47 base::TimeDelta duration = end - start; | |
48 total_duration_ += duration; | |
49 max_duration_ = std::max(max_duration_, duration); | |
50 } | |
51 | |
52 void ShowResults() const { | |
53 VLOG(1) << name_ << " count: " << count_; | |
54 VLOG(1) << name_ << " total duration: " | |
55 << total_duration_.InMillisecondsF() << " ms"; | |
56 VLOG(1) << name_ << " average duration: " | |
57 << (total_duration_.InMillisecondsF() / static_cast<double>(count_)) | |
58 << " ms"; | |
59 VLOG(1) << name_ << " maximum duration: " | |
60 << max_duration_.InMillisecondsF() << " ms"; | |
61 } | |
62 | |
63 void Reset() { | |
64 count_ = 0; | |
65 total_duration_ = base::TimeDelta(); | |
66 max_duration_ = base::TimeDelta(); | |
67 } | |
68 | |
69 private: | |
70 const std::string name_; | |
71 | |
72 uint64 count_; | |
73 base::TimeDelta total_duration_; | |
74 base::TimeDelta max_duration_; | |
75 | |
76 DISALLOW_COPY_AND_ASSIGN(EventTimeTracker); | |
77 }; | |
78 | |
79 // This channel listener just replies to all messages with the exact same | |
80 // message. It assumes each message has one string parameter. When the string | |
81 // "quit" is sent, it will exit. | |
82 class ChannelReflectorListener : public IPC::Listener { | |
83 public: | |
84 ChannelReflectorListener() | |
85 : channel_(NULL), | |
86 latency_tracker_("Client messages") { | |
87 VLOG(1) << "Client listener up"; | |
88 } | |
89 | |
90 virtual ~ChannelReflectorListener() { | |
91 VLOG(1) << "Client listener down"; | |
92 latency_tracker_.ShowResults(); | |
93 } | |
94 | |
95 void Init(IPC::Channel* channel) { | |
96 DCHECK(!channel_); | |
97 channel_ = channel; | |
98 } | |
99 | |
100 virtual bool OnMessageReceived(const IPC::Message& message) OVERRIDE { | |
101 CHECK(channel_); | |
102 | |
103 PickleIterator iter(message); | |
104 int64 time_internal; | |
105 EXPECT_TRUE(iter.ReadInt64(&time_internal)); | |
106 int msgid; | |
107 EXPECT_TRUE(iter.ReadInt(&msgid)); | |
108 std::string payload; | |
109 EXPECT_TRUE(iter.ReadString(&payload)); | |
110 | |
111 // Include message deserialization in latency. | |
112 base::TimeTicks now = base::TimeTicks::Now(); | |
113 | |
114 if (payload == "hello") { | |
115 latency_tracker_.Reset(); | |
116 } else if (payload == "quit") { | |
117 latency_tracker_.ShowResults(); | |
118 base::MessageLoop::current()->QuitWhenIdle(); | |
119 return true; | |
120 } else { | |
121 // Don't track hello and quit messages. | |
122 latency_tracker_.AddEvent( | |
123 base::TimeTicks::FromInternalValue(time_internal), now); | |
124 } | |
125 | |
126 IPC::Message* msg = new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL); | |
127 msg->WriteInt64(base::TimeTicks::Now().ToInternalValue()); | |
128 msg->WriteInt(msgid); | |
129 msg->WriteString(payload); | |
130 channel_->Send(msg); | |
131 return true; | |
132 } | |
133 | |
134 private: | |
135 IPC::Channel* channel_; | |
136 EventTimeTracker latency_tracker_; | |
137 }; | |
138 | |
139 class PerformanceChannelListener : public IPC::Listener { | |
140 public: | |
141 explicit PerformanceChannelListener(const std::string& label) | |
142 : label_(label), | |
143 sender_(NULL), | |
144 msg_count_(0), | |
145 msg_size_(0), | |
146 count_down_(0), | |
147 latency_tracker_("Server messages") { | |
148 VLOG(1) << "Server listener up"; | |
149 } | |
150 | |
151 virtual ~PerformanceChannelListener() { | |
152 VLOG(1) << "Server listener down"; | |
153 } | |
154 | |
155 void Init(IPC::Sender* sender) { | |
156 DCHECK(!sender_); | |
157 sender_ = sender; | |
158 } | |
159 | |
160 // Call this before running the message loop. | |
161 void SetTestParams(int msg_count, size_t msg_size) { | |
162 DCHECK_EQ(0, count_down_); | |
163 msg_count_ = msg_count; | |
164 msg_size_ = msg_size; | |
165 count_down_ = msg_count_; | |
166 payload_ = std::string(msg_size_, 'a'); | |
167 } | |
168 | |
169 virtual bool OnMessageReceived(const IPC::Message& message) OVERRIDE { | |
170 CHECK(sender_); | |
171 | |
172 PickleIterator iter(message); | |
173 int64 time_internal; | |
174 EXPECT_TRUE(iter.ReadInt64(&time_internal)); | |
175 int msgid; | |
176 EXPECT_TRUE(iter.ReadInt(&msgid)); | |
177 std::string reflected_payload; | |
178 EXPECT_TRUE(iter.ReadString(&reflected_payload)); | |
179 | |
180 // Include message deserialization in latency. | |
181 base::TimeTicks now = base::TimeTicks::Now(); | |
182 | |
183 if (reflected_payload == "hello") { | |
184 // Start timing on hello. | |
185 latency_tracker_.Reset(); | |
186 DCHECK(!perf_logger_.get()); | |
187 std::string test_name = | |
188 base::StringPrintf("IPC_%s_Perf_%dx_%u", | |
189 label_.c_str(), | |
190 msg_count_, | |
191 static_cast<unsigned>(msg_size_)); | |
192 perf_logger_.reset(new base::PerfTimeLogger(test_name.c_str())); | |
193 } else { | |
194 DCHECK_EQ(payload_.size(), reflected_payload.size()); | |
195 | |
196 latency_tracker_.AddEvent( | |
197 base::TimeTicks::FromInternalValue(time_internal), now); | |
198 | |
199 CHECK(count_down_ > 0); | |
200 count_down_--; | |
201 if (count_down_ == 0) { | |
202 perf_logger_.reset(); // Stop the perf timer now. | |
203 latency_tracker_.ShowResults(); | |
204 base::MessageLoop::current()->QuitWhenIdle(); | |
205 return true; | |
206 } | |
207 } | |
208 | |
209 IPC::Message* msg = new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL); | |
210 msg->WriteInt64(base::TimeTicks::Now().ToInternalValue()); | |
211 msg->WriteInt(count_down_); | |
212 msg->WriteString(payload_); | |
213 sender_->Send(msg); | |
214 return true; | |
215 } | |
216 | |
217 private: | |
218 std::string label_; | |
219 IPC::Sender* sender_; | |
220 int msg_count_; | |
221 size_t msg_size_; | |
222 | |
223 int count_down_; | |
224 std::string payload_; | |
225 EventTimeTracker latency_tracker_; | |
226 scoped_ptr<base::PerfTimeLogger> perf_logger_; | |
227 }; | 14 }; |
228 | 15 |
229 TEST_F(IPCChannelPerfTest, ChannelPingPong) { | 16 TEST_F(IPCChannelPerfTest, ChannelPingPong) { |
230 Init("PerformanceClient"); | 17 RunTestChannelPingPong(GetDefaultTestParams()); |
231 | |
232 // Set up IPC channel and start client. | |
233 PerformanceChannelListener listener("Channel"); | |
234 CreateChannel(&listener); | |
235 listener.Init(channel()); | |
236 ASSERT_TRUE(ConnectChannel()); | |
237 ASSERT_TRUE(StartClient()); | |
238 | |
239 // Test several sizes. We use 12^N for message size, and limit the message | |
240 // count to keep the test duration reasonable. | |
241 const size_t kMsgSize[5] = {12, 144, 1728, 20736, 248832}; | |
242 const int kMessageCount[5] = {50000, 50000, 50000, 12000, 1000}; | |
243 | |
244 for (size_t i = 0; i < 5; i++) { | |
245 listener.SetTestParams(kMessageCount[i], kMsgSize[i]); | |
246 | |
247 // This initial message will kick-start the ping-pong of messages. | |
248 IPC::Message* message = | |
249 new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL); | |
250 message->WriteInt64(base::TimeTicks::Now().ToInternalValue()); | |
251 message->WriteInt(-1); | |
252 message->WriteString("hello"); | |
253 sender()->Send(message); | |
254 | |
255 // Run message loop. | |
256 base::MessageLoop::current()->Run(); | |
257 } | |
258 | |
259 // Send quit message. | |
260 IPC::Message* message = new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL); | |
261 message->WriteInt64(base::TimeTicks::Now().ToInternalValue()); | |
262 message->WriteInt(-1); | |
263 message->WriteString("quit"); | |
264 sender()->Send(message); | |
265 | |
266 EXPECT_TRUE(WaitForClientShutdown()); | |
267 DestroyChannel(); | |
268 } | |
269 | |
270 // This message loop bounces all messages back to the sender. | |
271 MULTIPROCESS_IPC_TEST_CLIENT_MAIN(PerformanceClient) { | |
272 base::MessageLoopForIO main_message_loop; | |
273 ChannelReflectorListener listener; | |
274 scoped_ptr<IPC::Channel> channel(IPC::Channel::CreateClient( | |
275 IPCTestBase::GetChannelName("PerformanceClient"), &listener)); | |
276 listener.Init(channel.get()); | |
277 CHECK(channel->Connect()); | |
278 | |
279 base::MessageLoop::current()->Run(); | |
280 return 0; | |
281 } | 18 } |
282 | 19 |
283 TEST_F(IPCChannelPerfTest, ChannelProxyPingPong) { | 20 TEST_F(IPCChannelPerfTest, ChannelProxyPingPong) { |
284 InitWithCustomMessageLoop("PerformanceClient", | 21 RunTestChannelProxyPingPong(GetDefaultTestParams()); |
285 make_scoped_ptr(new base::MessageLoop())); | 22 } |
286 | 23 |
287 base::TestIOThread io_thread(base::TestIOThread::kAutoStart); | 24 MULTIPROCESS_IPC_TEST_CLIENT_MAIN(PerformanceClient) { |
288 | 25 IPC::test::PingPongTestClient client; |
289 // Set up IPC channel and start client. | 26 return client.RunMain(); |
290 PerformanceChannelListener listener("ChannelProxy"); | |
291 CreateChannelProxy(&listener, io_thread.task_runner()); | |
292 listener.Init(channel_proxy()); | |
293 ASSERT_TRUE(StartClient()); | |
294 | |
295 // Test several sizes. We use 12^N for message size, and limit the message | |
296 // count to keep the test duration reasonable. | |
297 const size_t kMsgSize[5] = {12, 144, 1728, 20736, 248832}; | |
298 const int kMessageCount[5] = {50000, 50000, 50000, 12000, 1000}; | |
299 | |
300 for (size_t i = 0; i < 5; i++) { | |
301 listener.SetTestParams(kMessageCount[i], kMsgSize[i]); | |
302 | |
303 // This initial message will kick-start the ping-pong of messages. | |
304 IPC::Message* message = | |
305 new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL); | |
306 message->WriteInt64(base::TimeTicks::Now().ToInternalValue()); | |
307 message->WriteInt(-1); | |
308 message->WriteString("hello"); | |
309 sender()->Send(message); | |
310 | |
311 // Run message loop. | |
312 base::MessageLoop::current()->Run(); | |
313 } | |
314 | |
315 // Send quit message. | |
316 IPC::Message* message = new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL); | |
317 message->WriteInt64(base::TimeTicks::Now().ToInternalValue()); | |
318 message->WriteInt(-1); | |
319 message->WriteString("quit"); | |
320 sender()->Send(message); | |
321 | |
322 EXPECT_TRUE(WaitForClientShutdown()); | |
323 DestroyChannelProxy(); | |
324 } | 27 } |
325 | 28 |
326 } // namespace | 29 } // namespace |
OLD | NEW |