blob: e7eeab9d8ea455e19785b4afd87496c04c3c83b2 [file] [log] [blame]
// Copyright (c) 2012 The Chromium Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
#include "build/build_config.h"
#include <algorithm>
#include <string>
#include "base/basictypes.h"
#include "base/logging.h"
#include "base/memory/scoped_ptr.h"
#include "base/pickle.h"
#include "base/strings/stringprintf.h"
#include "base/test/perf_time_logger.h"
#include "base/threading/thread.h"
#include "base/time/time.h"
#include "ipc/ipc_channel.h"
#include "ipc/ipc_channel_proxy.h"
#include "ipc/ipc_descriptors.h"
#include "ipc/ipc_message_utils.h"
#include "ipc/ipc_sender.h"
#include "ipc/ipc_test_base.h"
namespace {
// This test times the roundtrip IPC message cycle.
//
// TODO(brettw): Make this test run by default.
class IPCChannelPerfTest : public IPCTestBase {
};
// This class simply collects stats about abstract "events" (each of which has a
// start time and an end time).
class EventTimeTracker {
public:
explicit EventTimeTracker(const char* name)
: name_(name),
count_(0) {
}
void AddEvent(const base::TimeTicks& start, const base::TimeTicks& end) {
DCHECK(end >= start);
count_++;
base::TimeDelta duration = end - start;
total_duration_ += duration;
max_duration_ = std::max(max_duration_, duration);
}
void ShowResults() const {
VLOG(1) << name_ << " count: " << count_;
VLOG(1) << name_ << " total duration: "
<< total_duration_.InMillisecondsF() << " ms";
VLOG(1) << name_ << " average duration: "
<< (total_duration_.InMillisecondsF() / static_cast<double>(count_))
<< " ms";
VLOG(1) << name_ << " maximum duration: "
<< max_duration_.InMillisecondsF() << " ms";
}
void Reset() {
count_ = 0;
total_duration_ = base::TimeDelta();
max_duration_ = base::TimeDelta();
}
private:
const std::string name_;
uint64 count_;
base::TimeDelta total_duration_;
base::TimeDelta max_duration_;
DISALLOW_COPY_AND_ASSIGN(EventTimeTracker);
};
// This channel listener just replies to all messages with the exact same
// message. It assumes each message has one string parameter. When the string
// "quit" is sent, it will exit.
class ChannelReflectorListener : public IPC::Listener {
public:
ChannelReflectorListener()
: channel_(NULL),
latency_tracker_("Client messages") {
VLOG(1) << "Client listener up";
}
virtual ~ChannelReflectorListener() {
VLOG(1) << "Client listener down";
latency_tracker_.ShowResults();
}
void Init(IPC::Channel* channel) {
DCHECK(!channel_);
channel_ = channel;
}
virtual bool OnMessageReceived(const IPC::Message& message) OVERRIDE {
CHECK(channel_);
PickleIterator iter(message);
int64 time_internal;
EXPECT_TRUE(iter.ReadInt64(&time_internal));
int msgid;
EXPECT_TRUE(iter.ReadInt(&msgid));
std::string payload;
EXPECT_TRUE(iter.ReadString(&payload));
// Include message deserialization in latency.
base::TimeTicks now = base::TimeTicks::Now();
if (payload == "hello") {
latency_tracker_.Reset();
} else if (payload == "quit") {
latency_tracker_.ShowResults();
base::MessageLoop::current()->QuitWhenIdle();
return true;
} else {
// Don't track hello and quit messages.
latency_tracker_.AddEvent(
base::TimeTicks::FromInternalValue(time_internal), now);
}
IPC::Message* msg = new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL);
msg->WriteInt64(base::TimeTicks::Now().ToInternalValue());
msg->WriteInt(msgid);
msg->WriteString(payload);
channel_->Send(msg);
return true;
}
private:
IPC::Channel* channel_;
EventTimeTracker latency_tracker_;
};
class PerformanceChannelListener : public IPC::Listener {
public:
PerformanceChannelListener()
: channel_(NULL),
msg_count_(0),
msg_size_(0),
count_down_(0),
latency_tracker_("Server messages") {
VLOG(1) << "Server listener up";
}
virtual ~PerformanceChannelListener() {
VLOG(1) << "Server listener down";
}
void Init(IPC::Channel* channel) {
DCHECK(!channel_);
channel_ = channel;
}
// Call this before running the message loop.
void SetTestParams(int msg_count, size_t msg_size) {
DCHECK_EQ(0, count_down_);
msg_count_ = msg_count;
msg_size_ = msg_size;
count_down_ = msg_count_;
payload_ = std::string(msg_size_, 'a');
}
virtual bool OnMessageReceived(const IPC::Message& message) OVERRIDE {
CHECK(channel_);
PickleIterator iter(message);
int64 time_internal;
EXPECT_TRUE(iter.ReadInt64(&time_internal));
int msgid;
EXPECT_TRUE(iter.ReadInt(&msgid));
std::string reflected_payload;
EXPECT_TRUE(iter.ReadString(&reflected_payload));
// Include message deserialization in latency.
base::TimeTicks now = base::TimeTicks::Now();
if (reflected_payload == "hello") {
// Start timing on hello.
latency_tracker_.Reset();
DCHECK(!perf_logger_.get());
std::string test_name = base::StringPrintf(
"IPC_Perf_%dx_%u", msg_count_, static_cast<unsigned>(msg_size_));
perf_logger_.reset(new base::PerfTimeLogger(test_name.c_str()));
} else {
DCHECK_EQ(payload_.size(), reflected_payload.size());
latency_tracker_.AddEvent(
base::TimeTicks::FromInternalValue(time_internal), now);
CHECK(count_down_ > 0);
count_down_--;
if (count_down_ == 0) {
perf_logger_.reset(); // Stop the perf timer now.
latency_tracker_.ShowResults();
base::MessageLoop::current()->QuitWhenIdle();
return true;
}
}
IPC::Message* msg = new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL);
msg->WriteInt64(base::TimeTicks::Now().ToInternalValue());
msg->WriteInt(count_down_);
msg->WriteString(payload_);
channel_->Send(msg);
return true;
}
private:
IPC::Channel* channel_;
int msg_count_;
size_t msg_size_;
int count_down_;
std::string payload_;
EventTimeTracker latency_tracker_;
scoped_ptr<base::PerfTimeLogger> perf_logger_;
};
TEST_F(IPCChannelPerfTest, Performance) {
Init("PerformanceClient");
// Set up IPC channel and start client.
PerformanceChannelListener listener;
CreateChannel(&listener);
listener.Init(channel());
ASSERT_TRUE(ConnectChannel());
ASSERT_TRUE(StartClient());
const size_t kMsgSizeBase = 12;
const int kMsgSizeMaxExp = 5;
int msg_count = 100000;
size_t msg_size = kMsgSizeBase;
for (int i = 1; i <= kMsgSizeMaxExp; i++) {
listener.SetTestParams(msg_count, msg_size);
// This initial message will kick-start the ping-pong of messages.
IPC::Message* message =
new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL);
message->WriteInt64(base::TimeTicks::Now().ToInternalValue());
message->WriteInt(-1);
message->WriteString("hello");
sender()->Send(message);
// Run message loop.
base::MessageLoop::current()->Run();
msg_size *= kMsgSizeBase;
}
// Send quit message.
IPC::Message* message = new IPC::Message(0, 2, IPC::Message::PRIORITY_NORMAL);
message->WriteInt64(base::TimeTicks::Now().ToInternalValue());
message->WriteInt(-1);
message->WriteString("quit");
sender()->Send(message);
EXPECT_TRUE(WaitForClientShutdown());
DestroyChannel();
}
// This message loop bounces all messages back to the sender.
MULTIPROCESS_IPC_TEST_CLIENT_MAIN(PerformanceClient) {
base::MessageLoopForIO main_message_loop;
ChannelReflectorListener listener;
IPC::Channel channel(IPCTestBase::GetChannelName("PerformanceClient"),
IPC::Channel::MODE_CLIENT,
&listener);
listener.Init(&channel);
CHECK(channel.Connect());
base::MessageLoop::current()->Run();
return 0;
}
} // namespace