viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 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 | #include "build/build_config.h" |
| 6 | |
| 7 | #if defined(OS_WIN) |
| 8 | #include <windows.h> |
| 9 | #elif defined(OS_POSIX) |
| 10 | #include <sys/types.h> |
| 11 | #include <unistd.h> |
| 12 | #endif |
| 13 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 14 | #include <algorithm> |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 15 | #include <string> |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 16 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 17 | #include "base/basictypes.h" |
| 18 | #include "base/logging.h" |
| 19 | #include "base/memory/scoped_ptr.h" |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 20 | #include "base/perftimer.h" |
| 21 | #include "base/pickle.h" |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 22 | #include "base/stringprintf.h" |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 23 | #include "base/threading/thread.h" |
| 24 | #include "base/time.h" |
| 25 | #include "ipc/ipc_descriptors.h" |
| 26 | #include "ipc/ipc_channel.h" |
| 27 | #include "ipc/ipc_channel_proxy.h" |
| 28 | #include "ipc/ipc_message_utils.h" |
| 29 | #include "ipc/ipc_multiprocess_test.h" |
| 30 | #include "ipc/ipc_sender.h" |
viettrungluu@chromium.org | e977842 | 2013-01-12 06:19:15 +0900 | [diff] [blame] | 31 | #include "ipc/ipc_test_base.h" |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 32 | |
viettrungluu@chromium.org | 7ca1913 | 2013-01-12 05:56:22 +0900 | [diff] [blame] | 33 | namespace { |
| 34 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 35 | // This test times the roundtrip IPC message cycle. |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 36 | // |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 37 | // TODO(brettw): Make this test run by default. |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 38 | |
| 39 | class IPCChannelPerfTest : public IPCTestBase { |
| 40 | }; |
| 41 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 42 | // This class simply collects stats about abstract "events" (each of which has a |
| 43 | // start time and an end time). |
| 44 | class EventTimeTracker { |
| 45 | public: |
| 46 | explicit EventTimeTracker(const char* name) |
| 47 | : name_(name), |
| 48 | count_(0) { |
| 49 | } |
| 50 | |
| 51 | void AddEvent(const base::TimeTicks& start, const base::TimeTicks& end) { |
| 52 | DCHECK(end >= start); |
| 53 | count_++; |
| 54 | base::TimeDelta duration = end - start; |
| 55 | total_duration_ += duration; |
| 56 | max_duration_ = std::max(max_duration_, duration); |
| 57 | } |
| 58 | |
| 59 | void ShowResults() const { |
| 60 | VLOG(1) << name_ << " count: " << count_; |
| 61 | VLOG(1) << name_ << " total duration: " |
| 62 | << total_duration_.InMillisecondsF() << " ms"; |
| 63 | VLOG(1) << name_ << " average duration: " |
| 64 | << (total_duration_.InMillisecondsF() / static_cast<double>(count_)) |
| 65 | << " ms"; |
| 66 | VLOG(1) << name_ << " maximum duration: " |
| 67 | << max_duration_.InMillisecondsF() << " ms"; |
| 68 | } |
| 69 | |
| 70 | void Reset() { |
| 71 | count_ = 0; |
| 72 | total_duration_ = base::TimeDelta(); |
| 73 | max_duration_ = base::TimeDelta(); |
| 74 | } |
| 75 | |
| 76 | private: |
| 77 | const std::string name_; |
| 78 | |
| 79 | uint64 count_; |
| 80 | base::TimeDelta total_duration_; |
| 81 | base::TimeDelta max_duration_; |
| 82 | |
| 83 | DISALLOW_COPY_AND_ASSIGN(EventTimeTracker); |
| 84 | }; |
| 85 | |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 86 | // This channel listener just replies to all messages with the exact same |
| 87 | // message. It assumes each message has one string parameter. When the string |
| 88 | // "quit" is sent, it will exit. |
| 89 | class ChannelReflectorListener : public IPC::Listener { |
| 90 | public: |
viettrungluu@chromium.org | 721fe99 | 2013-01-17 04:33:32 +0900 | [diff] [blame] | 91 | ChannelReflectorListener() |
| 92 | : channel_(NULL), |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 93 | latency_tracker_("Client messages") { |
| 94 | VLOG(1) << "Client listener up"; |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 95 | } |
| 96 | |
| 97 | ~ChannelReflectorListener() { |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 98 | VLOG(1) << "Client listener down"; |
| 99 | latency_tracker_.ShowResults(); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 100 | } |
| 101 | |
viettrungluu@chromium.org | 721fe99 | 2013-01-17 04:33:32 +0900 | [diff] [blame] | 102 | void Init(IPC::Channel* channel) { |
| 103 | DCHECK(!channel_); |
| 104 | channel_ = channel; |
| 105 | } |
| 106 | |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 107 | virtual bool OnMessageReceived(const IPC::Message& message) { |
viettrungluu@chromium.org | 721fe99 | 2013-01-17 04:33:32 +0900 | [diff] [blame] | 108 | CHECK(channel_); |
| 109 | |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 110 | PickleIterator iter(message); |
| 111 | int64 time_internal; |
| 112 | EXPECT_TRUE(iter.ReadInt64(&time_internal)); |
| 113 | int msgid; |
| 114 | EXPECT_TRUE(iter.ReadInt(&msgid)); |
| 115 | std::string payload; |
| 116 | EXPECT_TRUE(iter.ReadString(&payload)); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 117 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 118 | // Include message deserialization in latency. |
| 119 | base::TimeTicks now = base::TimeTicks::Now(); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 120 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 121 | if (payload == "hello") { |
| 122 | latency_tracker_.Reset(); |
| 123 | } else if (payload == "quit") { |
| 124 | latency_tracker_.ShowResults(); |
| 125 | MessageLoop::current()->QuitWhenIdle(); |
| 126 | return true; |
| 127 | } else { |
| 128 | // Don't track hello and quit messages. |
| 129 | latency_tracker_.AddEvent( |
| 130 | base::TimeTicks::FromInternalValue(time_internal), now); |
| 131 | } |
| 132 | |
| 133 | IPC::Message* msg = new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 134 | msg->WriteInt64(base::TimeTicks::Now().ToInternalValue()); |
| 135 | msg->WriteInt(msgid); |
| 136 | msg->WriteString(payload); |
| 137 | channel_->Send(msg); |
| 138 | return true; |
| 139 | } |
| 140 | |
| 141 | private: |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 142 | IPC::Channel* channel_; |
| 143 | EventTimeTracker latency_tracker_; |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 144 | }; |
| 145 | |
| 146 | class ChannelPerfListener : public IPC::Listener { |
| 147 | public: |
viettrungluu@chromium.org | 721fe99 | 2013-01-17 04:33:32 +0900 | [diff] [blame] | 148 | ChannelPerfListener() |
| 149 | : channel_(NULL), |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 150 | msg_count_(0), |
| 151 | msg_size_(0), |
| 152 | count_down_(0), |
| 153 | latency_tracker_("Server messages") { |
| 154 | VLOG(1) << "Server listener up"; |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 155 | } |
| 156 | |
| 157 | ~ChannelPerfListener() { |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 158 | VLOG(1) << "Server listener down"; |
| 159 | } |
| 160 | |
viettrungluu@chromium.org | 721fe99 | 2013-01-17 04:33:32 +0900 | [diff] [blame] | 161 | void Init(IPC::Channel* channel) { |
| 162 | DCHECK(!channel_); |
| 163 | channel_ = channel; |
| 164 | } |
| 165 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 166 | // Call this before running the message loop. |
| 167 | void SetTestParams(int msg_count, size_t msg_size) { |
| 168 | DCHECK_EQ(0, count_down_); |
| 169 | msg_count_ = msg_count; |
| 170 | msg_size_ = msg_size; |
| 171 | count_down_ = msg_count_; |
| 172 | payload_ = std::string(msg_size_, 'a'); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 173 | } |
| 174 | |
| 175 | virtual bool OnMessageReceived(const IPC::Message& message) { |
viettrungluu@chromium.org | 721fe99 | 2013-01-17 04:33:32 +0900 | [diff] [blame] | 176 | CHECK(channel_); |
| 177 | |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 178 | PickleIterator iter(message); |
| 179 | int64 time_internal; |
| 180 | EXPECT_TRUE(iter.ReadInt64(&time_internal)); |
| 181 | int msgid; |
| 182 | EXPECT_TRUE(iter.ReadInt(&msgid)); |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 183 | std::string reflected_payload; |
| 184 | EXPECT_TRUE(iter.ReadString(&reflected_payload)); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 185 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 186 | // Include message deserialization in latency. |
| 187 | base::TimeTicks now = base::TimeTicks::Now(); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 188 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 189 | if (reflected_payload == "hello") { |
| 190 | // Start timing on hello. |
| 191 | latency_tracker_.Reset(); |
| 192 | DCHECK(!perf_logger_.get()); |
| 193 | std::string test_name = base::StringPrintf( |
| 194 | "IPC_Perf_%dx_%u", msg_count_, static_cast<unsigned>(msg_size_)); |
| 195 | perf_logger_.reset(new PerfTimeLogger(test_name.c_str())); |
| 196 | } else { |
| 197 | DCHECK_EQ(payload_.size(), reflected_payload.size()); |
| 198 | |
| 199 | latency_tracker_.AddEvent( |
| 200 | base::TimeTicks::FromInternalValue(time_internal), now); |
| 201 | |
| 202 | CHECK(count_down_ > 0); |
| 203 | count_down_--; |
| 204 | if (count_down_ == 0) { |
| 205 | perf_logger_.reset(); // Stop the perf timer now. |
| 206 | latency_tracker_.ShowResults(); |
| 207 | MessageLoop::current()->QuitWhenIdle(); |
| 208 | return true; |
| 209 | } |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 210 | } |
| 211 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 212 | IPC::Message* msg = new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 213 | msg->WriteInt64(base::TimeTicks::Now().ToInternalValue()); |
| 214 | msg->WriteInt(count_down_); |
| 215 | msg->WriteString(payload_); |
| 216 | channel_->Send(msg); |
| 217 | return true; |
| 218 | } |
| 219 | |
| 220 | private: |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 221 | IPC::Channel* channel_; |
| 222 | int msg_count_; |
| 223 | size_t msg_size_; |
| 224 | |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 225 | int count_down_; |
| 226 | std::string payload_; |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 227 | EventTimeTracker latency_tracker_; |
| 228 | scoped_ptr<PerfTimeLogger> perf_logger_; |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 229 | }; |
| 230 | |
| 231 | TEST_F(IPCChannelPerfTest, Performance) { |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 232 | // Setup IPC channel. |
viettrungluu@chromium.org | 721fe99 | 2013-01-17 04:33:32 +0900 | [diff] [blame] | 233 | ChannelPerfListener perf_listener; |
| 234 | IPC::Channel chan(kReflectorChannel, IPC::Channel::MODE_SERVER, |
| 235 | &perf_listener); |
| 236 | perf_listener.Init(&chan); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 237 | ASSERT_TRUE(chan.Connect()); |
| 238 | |
| 239 | base::ProcessHandle process_handle = SpawnChild(TEST_REFLECTOR, &chan); |
| 240 | ASSERT_TRUE(process_handle); |
| 241 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 242 | const size_t kMsgSizeBase = 12; |
| 243 | const int kMsgSizeMaxExp = 5; |
| 244 | int msg_count = 100000; |
| 245 | size_t msg_size = kMsgSizeBase; |
| 246 | for (int i = 1; i <= kMsgSizeMaxExp; i++) { |
| 247 | perf_listener.SetTestParams(msg_count, msg_size); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 248 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 249 | // This initial message will kick-start the ping-pong of messages. |
| 250 | IPC::Message* message = |
| 251 | new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL); |
| 252 | message->WriteInt64(base::TimeTicks::Now().ToInternalValue()); |
| 253 | message->WriteInt(-1); |
| 254 | message->WriteString("hello"); |
| 255 | chan.Send(message); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 256 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 257 | // Run message loop. |
| 258 | MessageLoop::current()->Run(); |
| 259 | |
| 260 | msg_size *= kMsgSizeBase; |
| 261 | } |
| 262 | |
| 263 | // Send quit message. |
| 264 | IPC::Message* message = new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 265 | message->WriteInt64(base::TimeTicks::Now().ToInternalValue()); |
| 266 | message->WriteInt(-1); |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 267 | message->WriteString("quit"); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 268 | chan.Send(message); |
| 269 | |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 270 | // Clean up child process. |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 271 | EXPECT_TRUE(base::WaitForSingleProcess(process_handle, |
| 272 | base::TimeDelta::FromSeconds(5))); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 273 | base::CloseProcessHandle(process_handle); |
| 274 | } |
| 275 | |
viettrungluu@chromium.org | 0615143 | 2013-01-16 05:14:22 +0900 | [diff] [blame] | 276 | // This message loop bounces all messages back to the sender. |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 277 | MULTIPROCESS_IPC_TEST_MAIN(RunReflector) { |
| 278 | MessageLoopForIO main_message_loop; |
viettrungluu@chromium.org | 721fe99 | 2013-01-17 04:33:32 +0900 | [diff] [blame] | 279 | ChannelReflectorListener channel_reflector_listener; |
| 280 | IPC::Channel chan(kReflectorChannel, IPC::Channel::MODE_CLIENT, |
| 281 | &channel_reflector_listener); |
| 282 | channel_reflector_listener.Init(&chan); |
viettrungluu@chromium.org | 7d86af2 | 2013-01-12 00:13:37 +0900 | [diff] [blame] | 283 | CHECK(chan.Connect()); |
| 284 | |
| 285 | MessageLoop::current()->Run(); |
| 286 | return 0; |
| 287 | } |
viettrungluu@chromium.org | 7ca1913 | 2013-01-12 05:56:22 +0900 | [diff] [blame] | 288 | |
| 289 | } // namespace |