summaryrefslogtreecommitdiffstats
path: root/extensions/browser
diff options
context:
space:
mode:
authorimcheng@chromium.org <imcheng@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98>2014-08-10 01:22:23 +0000
committerimcheng@chromium.org <imcheng@chromium.org@0039d316-1c4b-4281-b951-d872f2087c98>2014-08-10 01:24:04 +0000
commitec2cbc3974c9a4dc8a8fbab25fb304efaaab4c75 (patch)
treefb2924f4c37b7940cb6fec60d30501276b63cfd3 /extensions/browser
parentf09f968f9f0ba892cadca8574a382c41d4a979f9 (diff)
downloadchromium_src-ec2cbc3974c9a4dc8a8fbab25fb304efaaab4c75.zip
chromium_src-ec2cbc3974c9a4dc8a8fbab25fb304efaaab4c75.tar.gz
chromium_src-ec2cbc3974c9a4dc8a8fbab25fb304efaaab4c75.tar.bz2
Cast channel: Add logging to the cast channel API / cast sockets.
The logging system in cast channel API records: - lifetime of individual sockets created / closed - error codes from underlying socket / crypto operations - timeline view of cast socket's connection flow / read/write loop by defining and logging individual events for sockets Future patch will include overall statistics (e.g. # message / bytes). The logging system provides a single function GetLog() that will return a serialized version of the log. The log is in protocol buffer format. A couple of minor behavior changes: - Refactored the reset/state change logic in Close() into a DoClose() helper function. Make sure CloseWithError() also calls DoClose(). - If DoReadCallback() encounters error, change error_state_ so that it gets propagated back to delete_->OnError(). TODO: add cast channel API so that logs can be exported to extension. BUG=343228 Review URL: https://codereview.chromium.org/429443002 Cr-Commit-Position: refs/heads/master@{#288604} git-svn-id: svn://svn.chromium.org/chrome/trunk/src@288604 0039d316-1c4b-4281-b951-d872f2087c98
Diffstat (limited to 'extensions/browser')
-rw-r--r--extensions/browser/api/cast_channel/BUILD.gn5
-rw-r--r--extensions/browser/api/cast_channel/cast_auth_util.cc40
-rw-r--r--extensions/browser/api/cast_channel/cast_auth_util.h43
-rw-r--r--extensions/browser/api/cast_channel/cast_auth_util_nss.cc106
-rw-r--r--extensions/browser/api/cast_channel/cast_auth_util_openssl.cc6
-rw-r--r--extensions/browser/api/cast_channel/cast_channel_api.cc26
-rw-r--r--extensions/browser/api/cast_channel/cast_channel_api.h15
-rw-r--r--extensions/browser/api/cast_channel/cast_channel_apitest.cc19
-rw-r--r--extensions/browser/api/cast_channel/cast_socket.cc385
-rw-r--r--extensions/browser/api/cast_channel/cast_socket.h82
-rw-r--r--extensions/browser/api/cast_channel/cast_socket_unittest.cc40
-rw-r--r--extensions/browser/api/cast_channel/logger.cc277
-rw-r--r--extensions/browser/api/cast_channel/logger.h132
-rw-r--r--extensions/browser/api/cast_channel/logger_unittest.cc196
-rw-r--r--extensions/browser/api/cast_channel/logging.proto147
15 files changed, 1352 insertions, 167 deletions
diff --git a/extensions/browser/api/cast_channel/BUILD.gn b/extensions/browser/api/cast_channel/BUILD.gn
index e5a46da..8a8dc36 100644
--- a/extensions/browser/api/cast_channel/BUILD.gn
+++ b/extensions/browser/api/cast_channel/BUILD.gn
@@ -6,5 +6,8 @@ import("//third_party/protobuf/proto_library.gni")
# GYP version: extensions/extensions.gyp:cast_channel_proto
proto_library("cast_channel_proto") {
- sources = [ "cast_channel.proto" ]
+ sources = [
+ "cast_channel.proto",
+ "logging.proto",
+ ]
}
diff --git a/extensions/browser/api/cast_channel/cast_auth_util.cc b/extensions/browser/api/cast_channel/cast_auth_util.cc
new file mode 100644
index 0000000..767ef48
--- /dev/null
+++ b/extensions/browser/api/cast_channel/cast_auth_util.cc
@@ -0,0 +1,40 @@
+// Copyright 2014 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 "extensions/browser/api/cast_channel/cast_auth_util.h"
+
+namespace extensions {
+namespace core_api {
+namespace cast_channel {
+
+AuthResult::AuthResult() : error_type(ERROR_NONE), nss_error_code(0) {
+}
+
+AuthResult::~AuthResult() {
+}
+
+// static
+AuthResult AuthResult::Create(const std::string& error_message,
+ ErrorType error_type) {
+ return AuthResult(error_message, error_type, 0);
+}
+
+// static
+AuthResult AuthResult::CreateWithNSSError(const std::string& error_message,
+ ErrorType error_type,
+ int nss_error_code) {
+ return AuthResult(error_message, error_type, nss_error_code);
+}
+
+AuthResult::AuthResult(const std::string& error_message,
+ ErrorType error_type,
+ int nss_error_code)
+ : error_message(error_message),
+ error_type(error_type),
+ nss_error_code(nss_error_code) {
+}
+
+} // namespace cast_channel
+} // namespace core_api
+} // namespace extensions
diff --git a/extensions/browser/api/cast_channel/cast_auth_util.h b/extensions/browser/api/cast_channel/cast_auth_util.h
index 9fac2f4..560f698 100644
--- a/extensions/browser/api/cast_channel/cast_auth_util.h
+++ b/extensions/browser/api/cast_channel/cast_auth_util.h
@@ -13,11 +13,50 @@ namespace cast_channel {
class CastMessage;
+struct AuthResult {
+ public:
+ enum ErrorType {
+ ERROR_NONE,
+ ERROR_PEER_CERT_EMPTY,
+ ERROR_WRONG_PAYLOAD_TYPE,
+ ERROR_NO_PAYLOAD,
+ ERROR_PAYLOAD_PARSING_FAILED,
+ ERROR_MESSAGE_ERROR,
+ ERROR_NO_RESPONSE,
+ ERROR_FINGERPRINT_NOT_FOUND,
+ ERROR_NSS_CERT_PARSING_FAILED,
+ ERROR_NSS_CERT_NOT_SIGNED_BY_TRUSTED_CA,
+ ERROR_NSS_CANNOT_EXTRACT_PUBLIC_KEY,
+ ERROR_NSS_SIGNED_BLOBS_MISMATCH
+ };
+
+ // Constructs a AuthResult that corresponds to success.
+ AuthResult();
+ ~AuthResult();
+
+ static AuthResult Create(const std::string& error_message,
+ ErrorType error_type);
+ static AuthResult CreateWithNSSError(const std::string& error_message,
+ ErrorType error_type,
+ int nss_error_code);
+
+ bool success() const { return error_type == ERROR_NONE; }
+
+ std::string error_message;
+ ErrorType error_type;
+ int nss_error_code;
+
+ private:
+ AuthResult(const std::string& error_message,
+ ErrorType error_type,
+ int nss_error_code);
+};
+
// Authenticates the given |challenge_reply|:
// 1. Signature contained in the reply is valid.
// 2. Certficate used to sign is rooted to a trusted CA.
-bool AuthenticateChallengeReply(const CastMessage& challenge_reply,
- const std::string& peer_cert);
+AuthResult AuthenticateChallengeReply(const CastMessage& challenge_reply,
+ const std::string& peer_cert);
} // namespace cast_channel
} // namespace core_api
diff --git a/extensions/browser/api/cast_channel/cast_auth_util_nss.cc b/extensions/browser/api/cast_channel/cast_auth_util_nss.cc
index 9937286..34d2ab2 100644
--- a/extensions/browser/api/cast_channel/cast_auth_util_nss.cc
+++ b/extensions/browser/api/cast_channel/cast_auth_util_nss.cc
@@ -11,6 +11,7 @@
#include <string>
#include "base/logging.h"
+#include "base/strings/stringprintf.h"
#include "crypto/nss_util.h"
#include "crypto/scoped_nss_types.h"
#include "extensions/browser/api/cast_channel/cast_channel.pb.h"
@@ -187,37 +188,49 @@ static int GetICAWithFingerprint(const net::SHA1HashValue& fingerprint) {
}
// Parses out DeviceAuthMessage from CastMessage
-static bool ParseAuthMessage(const CastMessage& challenge_reply,
- DeviceAuthMessage* auth_message) {
+static AuthResult ParseAuthMessage(const CastMessage& challenge_reply,
+ DeviceAuthMessage* auth_message) {
+ const std::string kErrorPrefix("Failed to parse auth message: ");
if (challenge_reply.payload_type() != CastMessage_PayloadType_BINARY) {
- VLOG(1) << "Wrong payload type in challenge reply";
- return false;
+ return AuthResult::Create(
+ kErrorPrefix + "Wrong payload type in challenge reply",
+ AuthResult::ERROR_WRONG_PAYLOAD_TYPE);
}
if (!challenge_reply.has_payload_binary()) {
- VLOG(1) << "Payload type is binary but payload_binary field not set";
- return false;
+ return AuthResult::Create(
+ kErrorPrefix +
+ "Payload type is binary but payload_binary field not set",
+ AuthResult::ERROR_NO_PAYLOAD);
}
if (!auth_message->ParseFromString(challenge_reply.payload_binary())) {
- VLOG(1) << "Cannot parse binary payload into DeviceAuthMessage";
- return false;
+ return AuthResult::Create(
+ kErrorPrefix + "Cannot parse binary payload into DeviceAuthMessage",
+ AuthResult::ERROR_PAYLOAD_PARSING_FAILED);
}
+
VLOG(1) << "Auth message: " << AuthMessageToString(*auth_message);
+
if (auth_message->has_error()) {
- VLOG(1) << "Auth message error: " << auth_message->error().error_type();
- return false;
+ std::string error_format_str = kErrorPrefix + "Auth message error: %d";
+ return AuthResult::Create(
+ base::StringPrintf(error_format_str.c_str(),
+ auth_message->error().error_type()),
+ AuthResult::ERROR_MESSAGE_ERROR);
}
if (!auth_message->has_response()) {
- VLOG(1) << "Auth message has no response field";
- return false;
+ return AuthResult::Create(
+ kErrorPrefix + "Auth message has no response field",
+ AuthResult::ERROR_NO_RESPONSE);
}
- return true;
+ return AuthResult();
}
// Authenticates the given credentials:
// 1. |signature| verification of |data| using |certificate|.
// 2. |certificate| is signed by a trusted CA.
-bool VerifyCredentials(const AuthResponse& response,
- const std::string& data) {
+AuthResult VerifyCredentials(const AuthResponse& response,
+ const std::string& data) {
+ const std::string kErrorPrefix("Failed to verify credentials: ");
const std::string& certificate = response.client_auth_certificate();
const std::string& signature = response.signature();
@@ -228,7 +241,9 @@ bool VerifyCredentials(const AuthResponse& response,
// Otherwise, use the first intermediate in the list as long as it
// is in the allowed list of intermediates.
int num_intermediates = response.intermediate_certificate_size();
+
VLOG(1) << "Response has " << num_intermediates << " intermediates";
+
if (num_intermediates <= 0) {
trusted_ca_key_der = &kAllowedICAs[0].public_key;
} else {
@@ -237,8 +252,8 @@ bool VerifyCredentials(const AuthResponse& response,
= net::X509Certificate::CreateFromBytes(ica.data(), ica.length());
int index = GetICAWithFingerprint(ica_cert->fingerprint());
if (index == -1) {
- VLOG(1) << "Disallowed intermdiate cert";
- return false;
+ return AuthResult::Create(kErrorPrefix + "Disallowed intermediate cert",
+ AuthResult::ERROR_FINGERPRINT_NOT_FOUND);
}
trusted_ca_key_der = &kAllowedICAs[index].public_key;
}
@@ -255,8 +270,10 @@ bool VerifyCredentials(const AuthResponse& response,
ScopedCERTCertificate cert(CERT_NewTempCertificate(
CERT_GetDefaultCertDB(), &der_cert, NULL, PR_FALSE, PR_TRUE));
if (!cert.get()) {
- VLOG(1) << "Failed to parse certificate.";
- return false;
+ return AuthResult::CreateWithNSSError(
+ kErrorPrefix + "Failed to parse certificate.",
+ AuthResult::ERROR_NSS_CERT_PARSING_FAILED,
+ PORT_GetError());
}
// Check that the certificate is signed by trusted CA.
@@ -269,16 +286,21 @@ bool VerifyCredentials(const AuthResponse& response,
SECStatus verified = CERT_VerifySignedDataWithPublicKey(
&cert->signatureWrap, ca_public_key.get(), NULL);
if (verified != SECSuccess) {
- VLOG(1)<< "Cert not signed by trusted CA";
- return false;
+ return AuthResult::CreateWithNSSError(
+ kErrorPrefix + "Cert not signed by trusted CA",
+ AuthResult::ERROR_NSS_CERT_NOT_SIGNED_BY_TRUSTED_CA,
+ PORT_GetError());
}
+
VLOG(1) << "Cert signed by trusted CA";
// Verify that the |signature| matches |data|.
crypto::ScopedSECKEYPublicKey public_key(CERT_ExtractPublicKey(cert.get()));
if (!public_key.get()) {
- VLOG(1) << "Unable to extract public key from certificate.";
- return false;
+ return AuthResult::CreateWithNSSError(
+ kErrorPrefix + "Unable to extract public key from certificate",
+ AuthResult::ERROR_NSS_CANNOT_EXTRACT_PUBLIC_KEY,
+ PORT_GetError());
}
SECItem signature_item;
signature_item.type = siBuffer;
@@ -294,27 +316,45 @@ bool VerifyCredentials(const AuthResponse& response,
SEC_OID_SHA1, NULL, NULL);
if (verified != SECSuccess) {
- VLOG(1) << "Signed blobs did not match.";
- return false;
+ return AuthResult::CreateWithNSSError(
+ kErrorPrefix + "Signed blobs did not match",
+ AuthResult::ERROR_NSS_SIGNED_BLOBS_MISMATCH,
+ PORT_GetError());
}
+
VLOG(1) << "Signature verification succeeded";
- return true;
+
+ return AuthResult();
}
} // namespace
-bool AuthenticateChallengeReply(const CastMessage& challenge_reply,
- const std::string& peer_cert) {
- if (peer_cert.empty())
- return false;
+AuthResult AuthenticateChallengeReply(const CastMessage& challenge_reply,
+ const std::string& peer_cert) {
+ if (peer_cert.empty()) {
+ AuthResult result = AuthResult::Create("Peer cert was empty.",
+ AuthResult::ERROR_PEER_CERT_EMPTY);
+ VLOG(1) << result.error_message;
+ return result;
+ }
VLOG(1) << "Challenge reply: " << CastMessageToString(challenge_reply);
DeviceAuthMessage auth_message;
- if (!ParseAuthMessage(challenge_reply, &auth_message))
- return false;
+ AuthResult result = ParseAuthMessage(challenge_reply, &auth_message);
+ if (!result.success()) {
+ VLOG(1) << result.error_message;
+ return result;
+ }
const AuthResponse& response = auth_message.response();
- return VerifyCredentials(response, peer_cert);
+ result = VerifyCredentials(response, peer_cert);
+ if (!result.success()) {
+ VLOG(1) << result.error_message
+ << ", NSS error code: " << result.nss_error_code;
+ return result;
+ }
+
+ return AuthResult();
}
} // namespace cast_channel
diff --git a/extensions/browser/api/cast_channel/cast_auth_util_openssl.cc b/extensions/browser/api/cast_channel/cast_auth_util_openssl.cc
index 04795ca..3ebceed 100644
--- a/extensions/browser/api/cast_channel/cast_auth_util_openssl.cc
+++ b/extensions/browser/api/cast_channel/cast_auth_util_openssl.cc
@@ -10,10 +10,10 @@ namespace extensions {
namespace core_api {
namespace cast_channel {
-bool AuthenticateChallengeReply(const CastMessage& challenge_reply,
- const std::string& peer_cert) {
+AuthResult AuthenticateChallengeReply(const CastMessage& challenge_reply,
+ const std::string& peer_cert) {
NOTREACHED();
- return false;
+ return AuthResult();
}
} // namespace cast_channel
diff --git a/extensions/browser/api/cast_channel/cast_channel_api.cc b/extensions/browser/api/cast_channel/cast_channel_api.cc
index bf71053..e992a49 100644
--- a/extensions/browser/api/cast_channel/cast_channel_api.cc
+++ b/extensions/browser/api/cast_channel/cast_channel_api.cc
@@ -10,9 +10,12 @@
#include "base/json/json_writer.h"
#include "base/memory/scoped_ptr.h"
#include "base/strings/string_number_conversions.h"
+#include "base/time/default_tick_clock.h"
#include "base/values.h"
#include "content/public/browser/browser_thread.h"
#include "extensions/browser/api/cast_channel/cast_socket.h"
+#include "extensions/browser/api/cast_channel/logger.h"
+#include "extensions/browser/api/cast_channel/logging.pb.h"
#include "extensions/browser/event_router.h"
#include "net/base/ip_endpoint.h"
#include "net/base/net_errors.h"
@@ -35,6 +38,7 @@ using cast_channel::ChannelAuthType;
using cast_channel::ChannelError;
using cast_channel::ChannelInfo;
using cast_channel::ConnectInfo;
+using cast_channel::Logger;
using cast_channel::MessageInfo;
using cast_channel::ReadyState;
using content::BrowserThread;
@@ -81,7 +85,10 @@ bool IsValidConnectInfoIpAddress(const ConnectInfo& connect_info) {
} // namespace
CastChannelAPI::CastChannelAPI(content::BrowserContext* context)
- : browser_context_(context) {
+ : browser_context_(context),
+ logger_(
+ new Logger(scoped_ptr<base::TickClock>(new base::DefaultTickClock),
+ base::TimeTicks::UnixEpoch())) {
DCHECK(browser_context_);
}
@@ -90,6 +97,10 @@ CastChannelAPI* CastChannelAPI::Get(content::BrowserContext* context) {
return BrowserContextKeyedAPIFactory<CastChannelAPI>::Get(context);
}
+scoped_refptr<Logger> CastChannelAPI::GetLogger() {
+ return logger_;
+}
+
static base::LazyInstance<BrowserContextKeyedAPIFactory<CastChannelAPI> >
g_factory = LAZY_INSTANCE_INITIALIZER;
@@ -106,9 +117,13 @@ scoped_ptr<CastSocket> CastChannelAPI::CreateCastSocket(
return socket_for_test_.Pass();
} else {
return scoped_ptr<CastSocket>(
- new CastSocket(extension_id, ip_endpoint, channel_auth, this,
+ new CastSocket(extension_id,
+ ip_endpoint,
+ channel_auth,
+ this,
ExtensionsBrowserClient::Get()->GetNetLog(),
- timeout));
+ timeout,
+ logger_));
}
}
@@ -335,8 +350,9 @@ void CastChannelOpenFunction::AsyncWorkStart() {
? *connect_info_->timeout
: kDefaultConnectTimeoutMillis));
new_channel_id_ = AddSocket(socket.release());
- GetSocket(new_channel_id_)->Connect(
- base::Bind(&CastChannelOpenFunction::OnOpen, this));
+ CastSocket* new_socket = GetSocket(new_channel_id_);
+ api_->GetLogger()->LogNewSocketEvent(*new_socket);
+ new_socket->Connect(base::Bind(&CastChannelOpenFunction::OnOpen, this));
}
void CastChannelOpenFunction::OnOpen(int result) {
diff --git a/extensions/browser/api/cast_channel/cast_channel_api.h b/extensions/browser/api/cast_channel/cast_channel_api.h
index 3e07711..4abeff3 100644
--- a/extensions/browser/api/cast_channel/cast_channel_api.h
+++ b/extensions/browser/api/cast_channel/cast_channel_api.h
@@ -8,6 +8,7 @@
#include <string>
#include "base/basictypes.h"
+#include "base/memory/ref_counted.h"
#include "base/memory/scoped_ptr.h"
#include "base/threading/thread_checker.h"
#include "extensions/browser/api/api_resource_manager.h"
@@ -29,6 +30,12 @@ class IPEndPoint;
namespace extensions {
+namespace core_api {
+namespace cast_channel {
+class Logger;
+} // namespace cast_channel
+} // namespace core_api
+
namespace cast_channel = core_api::cast_channel;
class CastChannelAPI : public BrowserContextKeyedAPI,
@@ -49,6 +56,13 @@ class CastChannelAPI : public BrowserContextKeyedAPI,
cast_channel::ChannelAuthType channel_auth,
const base::TimeDelta& timeout);
+ // Returns a pointer to the Logger member variable.
+ // TODO(imcheng): Consider whether it is possible for this class to own the
+ // CastSockets and make this class the sole owner of Logger. Alternatively,
+ // consider making Logger not ref-counted by passing a weak
+ // reference of Logger to the CastSockets instead.
+ scoped_refptr<cast_channel::Logger> GetLogger();
+
// Sets the CastSocket instance to be returned by CreateCastSocket for
// testing.
void SetSocketForTest(scoped_ptr<cast_channel::CastSocket> socket_for_test);
@@ -69,6 +83,7 @@ class CastChannelAPI : public BrowserContextKeyedAPI,
static const char* service_name() { return "CastChannelAPI"; }
content::BrowserContext* const browser_context_;
+ scoped_refptr<cast_channel::Logger> logger_;
scoped_ptr<cast_channel::CastSocket> socket_for_test_;
DISALLOW_COPY_AND_ASSIGN(CastChannelAPI);
diff --git a/extensions/browser/api/cast_channel/cast_channel_apitest.cc b/extensions/browser/api/cast_channel/cast_channel_apitest.cc
index 9f56d2d..69e2d8f 100644
--- a/extensions/browser/api/cast_channel/cast_channel_apitest.cc
+++ b/extensions/browser/api/cast_channel/cast_channel_apitest.cc
@@ -12,6 +12,7 @@
#include "content/public/browser/browser_thread.h"
#include "extensions/browser/api/cast_channel/cast_channel_api.h"
#include "extensions/browser/api/cast_channel/cast_socket.h"
+#include "extensions/browser/api/cast_channel/logger.h"
#include "extensions/common/api/cast_channel.h"
#include "extensions/common/switches.h"
#include "net/base/capturing_net_log.h"
@@ -26,6 +27,7 @@
namespace cast_channel = extensions::core_api::cast_channel;
using cast_channel::CastSocket;
using cast_channel::ChannelError;
+using cast_channel::Logger;
using cast_channel::MessageInfo;
using cast_channel::ReadyState;
using extensions::Extension;
@@ -66,10 +68,15 @@ class MockCastSocket : public CastSocket {
public:
explicit MockCastSocket(CastSocket::Delegate* delegate,
net::IPEndPoint ip_endpoint,
- net::NetLog* net_log)
- : CastSocket(kTestExtensionId, ip_endpoint,
- cast_channel::CHANNEL_AUTH_TYPE_SSL, delegate, net_log,
- base::TimeDelta::FromMilliseconds(kTimeoutMs)) {}
+ net::NetLog* net_log,
+ Logger* logger)
+ : CastSocket(kTestExtensionId,
+ ip_endpoint,
+ cast_channel::CHANNEL_AUTH_TYPE_SSL,
+ delegate,
+ net_log,
+ base::TimeDelta::FromMilliseconds(kTimeoutMs),
+ logger) {}
virtual ~MockCastSocket() {}
MOCK_METHOD1(Connect, void(const net::CompletionCallback& callback));
@@ -98,8 +105,8 @@ class CastChannelAPITest : public ExtensionApiTest {
net::IPAddressNumber ip_number;
net::ParseIPLiteralToNumber("192.168.1.1", &ip_number);
net::IPEndPoint ip_endpoint(ip_number, 8009);
- mock_cast_socket_ = new MockCastSocket(api, ip_endpoint,
- &capturing_net_log_);
+ mock_cast_socket_ = new MockCastSocket(
+ api, ip_endpoint, &capturing_net_log_, api->GetLogger());
// Transfers ownership of the socket.
api->SetSocketForTest(
make_scoped_ptr<CastSocket>(mock_cast_socket_).Pass());
diff --git a/extensions/browser/api/cast_channel/cast_socket.cc b/extensions/browser/api/cast_channel/cast_socket.cc
index 80c9e85..e29d492 100644
--- a/extensions/browser/api/cast_channel/cast_socket.cc
+++ b/extensions/browser/api/cast_channel/cast_socket.cc
@@ -9,13 +9,16 @@
#include "base/bind.h"
#include "base/callback_helpers.h"
+#include "base/format_macros.h"
#include "base/lazy_instance.h"
#include "base/numerics/safe_conversions.h"
#include "base/strings/string_number_conversions.h"
+#include "base/strings/stringprintf.h"
#include "base/sys_byteorder.h"
#include "extensions/browser/api/cast_channel/cast_auth_util.h"
#include "extensions/browser/api/cast_channel/cast_channel.pb.h"
#include "extensions/browser/api/cast_channel/cast_message_util.h"
+#include "extensions/browser/api/cast_channel/logger.h"
#include "net/base/address_list.h"
#include "net/base/host_port_pair.h"
#include "net/base/net_errors.h"
@@ -63,28 +66,140 @@ ApiResourceManager<core_api::cast_channel::CastSocket>::GetFactoryInstance() {
namespace core_api {
namespace cast_channel {
+namespace {
+
+proto::ReadyState ReadyStateToProto(ReadyState state) {
+ switch (state) {
+ case READY_STATE_NONE:
+ return proto::READY_STATE_NONE;
+ case READY_STATE_CONNECTING:
+ return proto::READY_STATE_CONNECTING;
+ case READY_STATE_OPEN:
+ return proto::READY_STATE_OPEN;
+ case READY_STATE_CLOSING:
+ return proto::READY_STATE_CLOSING;
+ case READY_STATE_CLOSED:
+ return proto::READY_STATE_CLOSED;
+ default:
+ NOTREACHED();
+ return proto::READY_STATE_NONE;
+ }
+}
+
+proto::ConnectionState ConnectStateToProto(CastSocket::ConnectionState state) {
+ switch (state) {
+ case CastSocket::CONN_STATE_NONE:
+ return proto::CONN_STATE_NONE;
+ case CastSocket::CONN_STATE_TCP_CONNECT:
+ return proto::CONN_STATE_TCP_CONNECT;
+ case CastSocket::CONN_STATE_TCP_CONNECT_COMPLETE:
+ return proto::CONN_STATE_TCP_CONNECT_COMPLETE;
+ case CastSocket::CONN_STATE_SSL_CONNECT:
+ return proto::CONN_STATE_SSL_CONNECT;
+ case CastSocket::CONN_STATE_SSL_CONNECT_COMPLETE:
+ return proto::CONN_STATE_SSL_CONNECT_COMPLETE;
+ case CastSocket::CONN_STATE_AUTH_CHALLENGE_SEND:
+ return proto::CONN_STATE_AUTH_CHALLENGE_SEND;
+ case CastSocket::CONN_STATE_AUTH_CHALLENGE_SEND_COMPLETE:
+ return proto::CONN_STATE_AUTH_CHALLENGE_SEND_COMPLETE;
+ case CastSocket::CONN_STATE_AUTH_CHALLENGE_REPLY_COMPLETE:
+ return proto::CONN_STATE_AUTH_CHALLENGE_REPLY_COMPLETE;
+ default:
+ NOTREACHED();
+ return proto::CONN_STATE_NONE;
+ }
+}
+
+proto::ReadState ReadStateToProto(CastSocket::ReadState state) {
+ switch (state) {
+ case CastSocket::READ_STATE_NONE:
+ return proto::READ_STATE_NONE;
+ case CastSocket::READ_STATE_READ:
+ return proto::READ_STATE_READ;
+ case CastSocket::READ_STATE_READ_COMPLETE:
+ return proto::READ_STATE_READ_COMPLETE;
+ case CastSocket::READ_STATE_DO_CALLBACK:
+ return proto::READ_STATE_DO_CALLBACK;
+ case CastSocket::READ_STATE_ERROR:
+ return proto::READ_STATE_ERROR;
+ default:
+ NOTREACHED();
+ return proto::READ_STATE_NONE;
+ }
+}
+
+proto::WriteState WriteStateToProto(CastSocket::WriteState state) {
+ switch (state) {
+ case CastSocket::WRITE_STATE_NONE:
+ return proto::WRITE_STATE_NONE;
+ case CastSocket::WRITE_STATE_WRITE:
+ return proto::WRITE_STATE_WRITE;
+ case CastSocket::WRITE_STATE_WRITE_COMPLETE:
+ return proto::WRITE_STATE_WRITE_COMPLETE;
+ case CastSocket::WRITE_STATE_DO_CALLBACK:
+ return proto::WRITE_STATE_DO_CALLBACK;
+ case CastSocket::WRITE_STATE_ERROR:
+ return proto::WRITE_STATE_ERROR;
+ default:
+ NOTREACHED();
+ return proto::WRITE_STATE_NONE;
+ }
+}
+
+proto::ErrorState ErrorStateToProto(ChannelError state) {
+ switch (state) {
+ case CHANNEL_ERROR_NONE:
+ return proto::CHANNEL_ERROR_NONE;
+ case CHANNEL_ERROR_CHANNEL_NOT_OPEN:
+ return proto::CHANNEL_ERROR_CHANNEL_NOT_OPEN;
+ case CHANNEL_ERROR_AUTHENTICATION_ERROR:
+ return proto::CHANNEL_ERROR_AUTHENTICATION_ERROR;
+ case CHANNEL_ERROR_CONNECT_ERROR:
+ return proto::CHANNEL_ERROR_CONNECT_ERROR;
+ case CHANNEL_ERROR_SOCKET_ERROR:
+ return proto::CHANNEL_ERROR_SOCKET_ERROR;
+ case CHANNEL_ERROR_TRANSPORT_ERROR:
+ return proto::CHANNEL_ERROR_TRANSPORT_ERROR;
+ case CHANNEL_ERROR_INVALID_MESSAGE:
+ return proto::CHANNEL_ERROR_INVALID_MESSAGE;
+ case CHANNEL_ERROR_INVALID_CHANNEL_ID:
+ return proto::CHANNEL_ERROR_INVALID_CHANNEL_ID;
+ case CHANNEL_ERROR_CONNECT_TIMEOUT:
+ return proto::CHANNEL_ERROR_CONNECT_TIMEOUT;
+ case CHANNEL_ERROR_UNKNOWN:
+ return proto::CHANNEL_ERROR_UNKNOWN;
+ default:
+ NOTREACHED();
+ return proto::CHANNEL_ERROR_NONE;
+ }
+}
+
+} // namespace
+
CastSocket::CastSocket(const std::string& owner_extension_id,
const net::IPEndPoint& ip_endpoint,
ChannelAuthType channel_auth,
CastSocket::Delegate* delegate,
net::NetLog* net_log,
- const base::TimeDelta& timeout) :
- ApiResource(owner_extension_id),
- channel_id_(0),
- ip_endpoint_(ip_endpoint),
- channel_auth_(channel_auth),
- delegate_(delegate),
- current_message_size_(0),
- current_message_(new CastMessage()),
- net_log_(net_log),
- connect_timeout_(timeout),
- connect_timeout_timer_(new base::OneShotTimer<CastSocket>),
- is_canceled_(false),
- connect_state_(CONN_STATE_NONE),
- write_state_(WRITE_STATE_NONE),
- read_state_(READ_STATE_NONE),
- error_state_(CHANNEL_ERROR_NONE),
- ready_state_(READY_STATE_NONE) {
+ const base::TimeDelta& timeout,
+ const scoped_refptr<Logger>& logger)
+ : ApiResource(owner_extension_id),
+ channel_id_(0),
+ ip_endpoint_(ip_endpoint),
+ channel_auth_(channel_auth),
+ delegate_(delegate),
+ current_message_size_(0),
+ current_message_(new CastMessage()),
+ net_log_(net_log),
+ logger_(logger),
+ connect_timeout_(timeout),
+ connect_timeout_timer_(new base::OneShotTimer<CastSocket>),
+ is_canceled_(false),
+ connect_state_(CONN_STATE_NONE),
+ write_state_(WRITE_STATE_NONE),
+ read_state_(READ_STATE_NONE),
+ error_state_(CHANNEL_ERROR_NONE),
+ ready_state_(READY_STATE_NONE) {
DCHECK(net_log_);
DCHECK(channel_auth_ == CHANNEL_AUTH_TYPE_SSL ||
channel_auth_ == CHANNEL_AUTH_TYPE_SSL_VERIFIED);
@@ -132,6 +247,7 @@ scoped_ptr<net::SSLClientSocket> CastSocket::CreateSslSocket(
cert_and_status.cert_status = net::CERT_STATUS_AUTHORITY_INVALID;
cert_and_status.der_cert = peer_cert_;
ssl_config.allowed_bad_certs.push_back(cert_and_status);
+ logger_->LogSocketEvent(channel_id_, proto::SSL_CERT_WHITELISTED);
}
cert_verifier_.reset(net::CertVerifier::CreateDefault());
@@ -157,32 +273,44 @@ bool CastSocket::ExtractPeerCert(std::string* cert) {
net::SSLInfo ssl_info;
if (!socket_->GetSSLInfo(&ssl_info) || !ssl_info.cert.get())
return false;
+
+ logger_->LogSocketEvent(channel_id_, proto::SSL_INFO_OBTAINED);
+
bool result = net::X509Certificate::GetDEREncoded(
ssl_info.cert->os_cert_handle(), cert);
if (result)
VLOG_WITH_CONNECTION(1) << "Successfully extracted peer certificate: "
<< *cert;
+
+ logger_->LogSocketEventWithRv(
+ channel_id_, proto::DER_ENCODED_CERT_OBTAIN, result ? 1 : 0);
return result;
}
bool CastSocket::VerifyChallengeReply() {
- return AuthenticateChallengeReply(*challenge_reply_, peer_cert_);
+ AuthResult result = AuthenticateChallengeReply(*challenge_reply_, peer_cert_);
+ logger_->LogSocketChallengeReplyEvent(channel_id_, result);
+ return result.success();
}
void CastSocket::Connect(const net::CompletionCallback& callback) {
DCHECK(CalledOnValidThread());
VLOG_WITH_CONNECTION(1) << "Connect readyState = " << ready_state_;
if (ready_state_ != READY_STATE_NONE) {
+ logger_->LogSocketEventWithDetails(
+ channel_id_, proto::CONNECT_FAILED, "ReadyState not NONE");
callback.Run(net::ERR_CONNECTION_FAILED);
return;
}
- ready_state_ = READY_STATE_CONNECTING;
+
connect_callback_ = callback;
- connect_state_ = CONN_STATE_TCP_CONNECT;
+ SetReadyState(READY_STATE_CONNECTING);
+ SetConnectState(CONN_STATE_TCP_CONNECT);
+
if (connect_timeout_.InMicroseconds() > 0) {
DCHECK(connect_timeout_callback_.IsCancelled());
- connect_timeout_callback_.Reset(base::Bind(&CastSocket::CancelConnect,
- base::Unretained(this)));
+ connect_timeout_callback_.Reset(
+ base::Bind(&CastSocket::OnConnectTimeout, base::Unretained(this)));
GetTimer()->Start(FROM_HERE,
connect_timeout_,
connect_timeout_callback_.callback());
@@ -200,10 +328,11 @@ void CastSocket::PostTaskToStartConnectLoop(int result) {
connect_loop_callback_.callback());
}
-void CastSocket::CancelConnect() {
+void CastSocket::OnConnectTimeout() {
DCHECK(CalledOnValidThread());
// Stop all pending connection setup tasks and report back to the client.
is_canceled_ = true;
+ logger_->LogSocketEvent(channel_id_, proto::CONNECT_TIMED_OUT);
VLOG_WITH_CONNECTION(1) << "Timeout while establishing a connection.";
DoConnectCallback(net::ERR_TIMED_OUT);
}
@@ -260,6 +389,13 @@ void CastSocket::DoConnectLoop(int result) {
// a. A network operation is pending, OR
// b. The Do* method called did not change state
+ // No state change occurred in do-while loop above. This means state has
+ // transitioned to NONE.
+ if (connect_state_ == CONN_STATE_NONE) {
+ logger_->LogSocketConnectState(channel_id_,
+ ConnectStateToProto(connect_state_));
+ }
+
// Connect loop is finished: if there is no pending IO invoke the callback.
if (rv != net::ERR_IO_PENDING) {
GetTimer()->Stop();
@@ -270,10 +406,13 @@ void CastSocket::DoConnectLoop(int result) {
int CastSocket::DoTcpConnect() {
DCHECK(connect_loop_callback_.IsCancelled());
VLOG_WITH_CONNECTION(1) << "DoTcpConnect";
- connect_state_ = CONN_STATE_TCP_CONNECT_COMPLETE;
+ SetConnectState(CONN_STATE_TCP_CONNECT_COMPLETE);
tcp_socket_ = CreateTcpSocket();
- return tcp_socket_->Connect(
+
+ int rv = tcp_socket_->Connect(
base::Bind(&CastSocket::DoConnectLoop, base::Unretained(this)));
+ logger_->LogSocketEventWithRv(channel_id_, proto::TCP_SOCKET_CONNECT, rv);
+ return rv;
}
int CastSocket::DoTcpConnectComplete(int result) {
@@ -282,7 +421,9 @@ int CastSocket::DoTcpConnectComplete(int result) {
// Enable TCP protocol-level keep-alive.
bool result = tcp_socket_->SetKeepAlive(true, kTcpKeepAliveDelaySecs);
LOG_IF(WARNING, !result) << "Failed to SetKeepAlive.";
- connect_state_ = CONN_STATE_SSL_CONNECT;
+ logger_->LogSocketEventWithRv(
+ channel_id_, proto::TCP_SOCKET_SET_KEEP_ALIVE, result ? 1 : 0);
+ SetConnectState(CONN_STATE_SSL_CONNECT);
}
return result;
}
@@ -290,27 +431,31 @@ int CastSocket::DoTcpConnectComplete(int result) {
int CastSocket::DoSslConnect() {
DCHECK(connect_loop_callback_.IsCancelled());
VLOG_WITH_CONNECTION(1) << "DoSslConnect";
- connect_state_ = CONN_STATE_SSL_CONNECT_COMPLETE;
+ SetConnectState(CONN_STATE_SSL_CONNECT_COMPLETE);
socket_ = CreateSslSocket(tcp_socket_.PassAs<net::StreamSocket>());
- return socket_->Connect(
+
+ int rv = socket_->Connect(
base::Bind(&CastSocket::DoConnectLoop, base::Unretained(this)));
+ logger_->LogSocketEventWithRv(channel_id_, proto::SSL_SOCKET_CONNECT, rv);
+ return rv;
}
int CastSocket::DoSslConnectComplete(int result) {
VLOG_WITH_CONNECTION(1) << "DoSslConnectComplete: " << result;
if (result == net::ERR_CERT_AUTHORITY_INVALID &&
peer_cert_.empty() && ExtractPeerCert(&peer_cert_)) {
- connect_state_ = CONN_STATE_TCP_CONNECT;
+ SetConnectState(CONN_STATE_TCP_CONNECT);
} else if (result == net::OK &&
channel_auth_ == CHANNEL_AUTH_TYPE_SSL_VERIFIED) {
- connect_state_ = CONN_STATE_AUTH_CHALLENGE_SEND;
+ SetConnectState(CONN_STATE_AUTH_CHALLENGE_SEND);
}
return result;
}
int CastSocket::DoAuthChallengeSend() {
VLOG_WITH_CONNECTION(1) << "DoAuthChallengeSend";
- connect_state_ = CONN_STATE_AUTH_CHALLENGE_SEND_COMPLETE;
+ SetConnectState(CONN_STATE_AUTH_CHALLENGE_SEND_COMPLETE);
+
CastMessage challenge_message;
CreateAuthChallengeMessage(&challenge_message);
VLOG_WITH_CONNECTION(1) << "Sending challenge: "
@@ -344,7 +489,8 @@ int CastSocket::DoAuthChallengeSendComplete(int result) {
VLOG_WITH_CONNECTION(1) << "DoAuthChallengeSendComplete: " << result;
if (result < 0)
return result;
- connect_state_ = CONN_STATE_AUTH_CHALLENGE_REPLY_COMPLETE;
+ SetConnectState(CONN_STATE_AUTH_CHALLENGE_REPLY_COMPLETE);
+
// Post a task to start read loop so that DoReadLoop is not nested inside
// DoConnectLoop. This is not strictly necessary but keeps the read loop
// code decoupled from connect loop code.
@@ -364,15 +510,17 @@ int CastSocket::DoAuthChallengeReplyComplete(int result) {
}
void CastSocket::DoConnectCallback(int result) {
- ready_state_ = (result == net::OK) ? READY_STATE_OPEN : READY_STATE_CLOSED;
+ SetReadyState((result == net::OK) ? READY_STATE_OPEN : READY_STATE_CLOSED);
+
if (result == net::OK) {
- error_state_ = CHANNEL_ERROR_NONE;
+ SetErrorState(CHANNEL_ERROR_NONE);
PostTaskToStartReadLoop();
} else if (result == net::ERR_TIMED_OUT) {
- error_state_ = CHANNEL_ERROR_CONNECT_TIMEOUT;
+ SetErrorState(CHANNEL_ERROR_CONNECT_TIMEOUT);
} else {
- error_state_ = CHANNEL_ERROR_CONNECT_ERROR;
+ SetErrorState(CHANNEL_ERROR_CONNECT_ERROR);
}
+
VLOG_WITH_CONNECTION(1) << "Calling Connect_Callback";
base::ResetAndReturn(&connect_callback_).Run(result);
}
@@ -391,6 +539,7 @@ void CastSocket::CloseInternal() {
if (ready_state_ == READY_STATE_CLOSED) {
return;
}
+
VLOG_WITH_CONNECTION(1) << "Close ReadyState = " << ready_state_;
tcp_socket_.reset();
socket_.reset();
@@ -404,7 +553,8 @@ void CastSocket::CloseInternal() {
send_auth_challenge_callback_.Cancel();
read_loop_callback_.Cancel();
connect_timeout_callback_.Cancel();
- ready_state_ = READY_STATE_CLOSED;
+ SetReadyState(READY_STATE_CLOSED);
+ logger_->LogSocketEvent(channel_id_, proto::SOCKET_CLOSED);
}
void CastSocket::RunPendingCallbacksOnClose() {
@@ -424,11 +574,19 @@ void CastSocket::SendMessage(const MessageInfo& message,
const net::CompletionCallback& callback) {
DCHECK(CalledOnValidThread());
if (ready_state_ != READY_STATE_OPEN) {
+ logger_->LogSocketEventForMessage(channel_id_,
+ proto::SEND_MESSAGE_FAILED,
+ message.namespace_,
+ "Ready state not OPEN");
callback.Run(net::ERR_FAILED);
return;
}
CastMessage message_proto;
if (!MessageInfoToCastMessage(message, &message_proto)) {
+ logger_->LogSocketEventForMessage(channel_id_,
+ proto::SEND_MESSAGE_FAILED,
+ message.namespace_,
+ "Failed to convert to CastMessage");
callback.Run(net::ERR_FAILED);
return;
}
@@ -440,13 +598,22 @@ void CastSocket::SendCastMessageInternal(
const net::CompletionCallback& callback) {
WriteRequest write_request(callback);
if (!write_request.SetContent(message)) {
+ logger_->LogSocketEventForMessage(channel_id_,
+ proto::SEND_MESSAGE_FAILED,
+ message.namespace_(),
+ "SetContent failed");
callback.Run(net::ERR_FAILED);
return;
}
write_queue_.push(write_request);
+ logger_->LogSocketEventForMessage(
+ channel_id_,
+ proto::MESSAGE_ENQUEUED,
+ message.namespace_(),
+ base::StringPrintf("Queue size: %" PRIuS, write_queue_.size()));
if (write_state_ == WRITE_STATE_NONE) {
- write_state_ = WRITE_STATE_WRITE;
+ SetWriteState(WRITE_STATE_WRITE);
DoWriteLoop(net::OK);
}
}
@@ -456,7 +623,7 @@ void CastSocket::DoWriteLoop(int result) {
VLOG_WITH_CONNECTION(1) << "DoWriteLoop queue size: " << write_queue_.size();
if (write_queue_.empty()) {
- write_state_ = WRITE_STATE_NONE;
+ SetWriteState(WRITE_STATE_NONE);
return;
}
@@ -489,14 +656,20 @@ void CastSocket::DoWriteLoop(int result) {
rv != net::ERR_IO_PENDING &&
write_state_ != WRITE_STATE_NONE);
+ // No state change occurred in do-while loop above. This means state has
+ // transitioned to NONE.
+ if (write_state_ == WRITE_STATE_NONE) {
+ logger_->LogSocketWriteState(channel_id_, WriteStateToProto(write_state_));
+ }
+
// If write loop is done because the queue is empty then set write
// state to NONE
if (write_queue_.empty())
- write_state_ = WRITE_STATE_NONE;
+ SetWriteState(WRITE_STATE_NONE);
// Write loop is done - if the result is ERR_FAILED then close with error.
if (rv == net::ERR_FAILED)
- CloseWithError(error_state_);
+ CloseWithError();
}
int CastSocket::DoWrite() {
@@ -507,18 +680,22 @@ int CastSocket::DoWrite() {
<< request.io_buffer->size() << " bytes_written "
<< request.io_buffer->BytesConsumed();
- write_state_ = WRITE_STATE_WRITE_COMPLETE;
- return socket_->Write(
+ SetWriteState(WRITE_STATE_WRITE_COMPLETE);
+
+ int rv = socket_->Write(
request.io_buffer.get(),
request.io_buffer->BytesRemaining(),
base::Bind(&CastSocket::DoWriteLoop, base::Unretained(this)));
+ logger_->LogSocketEventWithRv(channel_id_, proto::SOCKET_WRITE, rv);
+
+ return rv;
}
int CastSocket::DoWriteComplete(int result) {
DCHECK(!write_queue_.empty());
if (result <= 0) { // NOTE that 0 also indicates an error
- error_state_ = CHANNEL_ERROR_SOCKET_ERROR;
- write_state_ = WRITE_STATE_ERROR;
+ SetErrorState(CHANNEL_ERROR_SOCKET_ERROR);
+ SetWriteState(WRITE_STATE_ERROR);
return result == 0 ? net::ERR_FAILED : result;
}
@@ -527,9 +704,9 @@ int CastSocket::DoWriteComplete(int result) {
scoped_refptr<net::DrainableIOBuffer> io_buffer = request.io_buffer;
io_buffer->DidConsume(result);
if (io_buffer->BytesRemaining() == 0) // Message fully sent
- write_state_ = WRITE_STATE_DO_CALLBACK;
+ SetWriteState(WRITE_STATE_DO_CALLBACK);
else
- write_state_ = WRITE_STATE_WRITE;
+ SetWriteState(WRITE_STATE_WRITE);
return net::OK;
}
@@ -537,8 +714,14 @@ int CastSocket::DoWriteComplete(int result) {
int CastSocket::DoWriteCallback() {
DCHECK(!write_queue_.empty());
write_state_ = WRITE_STATE_WRITE;
+ logger_->LogSocketWriteState(channel_id_, WriteStateToProto(write_state_));
WriteRequest& request = write_queue_.front();
int bytes_consumed = request.io_buffer->BytesConsumed();
+ logger_->LogSocketEventForMessage(
+ channel_id_,
+ proto::MESSAGE_WRITTEN,
+ request.message_namespace,
+ base::StringPrintf("Bytes: %d", bytes_consumed));
request.callback.Run(bytes_consumed);
write_queue_.pop();
return net::OK;
@@ -580,7 +763,7 @@ void CastSocket::StartReadLoop() {
read_loop_callback_.Cancel();
// Read loop would have already been started if read state is not NONE
if (read_state_ == READ_STATE_NONE) {
- read_state_ = READ_STATE_READ;
+ SetReadState(READ_STATE_READ);
DoReadLoop(net::OK);
}
}
@@ -616,6 +799,12 @@ void CastSocket::DoReadLoop(int result) {
}
} while (rv != net::ERR_IO_PENDING && read_state_ != READ_STATE_NONE);
+ // No state change occurred in do-while loop above. This means state has
+ // transitioned to NONE.
+ if (read_state_ == READ_STATE_NONE) {
+ logger_->LogSocketReadState(channel_id_, ReadStateToProto(read_state_));
+ }
+
if (rv == net::ERR_FAILED) {
if (ready_state_ == READY_STATE_CONNECTING) {
// Read errors during the handshake should notify the caller via
@@ -624,13 +813,13 @@ void CastSocket::DoReadLoop(int result) {
} else {
// Connection is already established.
// Close and send error status via the message event delegate.
- CloseWithError(error_state_);
+ CloseWithError();
}
}
}
int CastSocket::DoRead() {
- read_state_ = READ_STATE_READ_COMPLETE;
+ SetReadState(READ_STATE_READ_COMPLETE);
// Figure out whether to read header or body, and the remaining bytes.
uint32 num_bytes_to_read = 0;
if (header_read_buffer_->RemainingCapacity() > 0) {
@@ -646,10 +835,13 @@ int CastSocket::DoRead() {
CHECK_GT(num_bytes_to_read, 0U);
// Read up to num_bytes_to_read into |current_read_buffer_|.
- return socket_->Read(
+ int rv = socket_->Read(
current_read_buffer_.get(),
num_bytes_to_read,
base::Bind(&CastSocket::DoReadLoop, base::Unretained(this)));
+ logger_->LogSocketEventWithRv(channel_id_, proto::SOCKET_READ, rv);
+
+ return rv;
}
int CastSocket::DoReadComplete(int result) {
@@ -659,8 +851,8 @@ int CastSocket::DoReadComplete(int result) {
<< " body offset = " << body_read_buffer_->offset();
if (result <= 0) { // 0 means EOF: the peer closed the socket
VLOG_WITH_CONNECTION(1) << "Read error, peer closed the socket";
- error_state_ = CHANNEL_ERROR_SOCKET_ERROR;
- read_state_ = READ_STATE_ERROR;
+ SetErrorState(CHANNEL_ERROR_SOCKET_ERROR);
+ SetReadState(READ_STATE_ERROR);
return result == 0 ? net::ERR_FAILED : result;
}
@@ -668,41 +860,55 @@ int CastSocket::DoReadComplete(int result) {
CHECK_LE(current_read_buffer_->offset() + result,
current_read_buffer_->capacity());
current_read_buffer_->set_offset(current_read_buffer_->offset() + result);
- read_state_ = READ_STATE_READ;
if (current_read_buffer_.get() == header_read_buffer_.get() &&
current_read_buffer_->RemainingCapacity() == 0) {
// A full header is read, process the contents.
if (!ProcessHeader()) {
- error_state_ = cast_channel::CHANNEL_ERROR_INVALID_MESSAGE;
- read_state_ = READ_STATE_ERROR;
+ SetErrorState(CHANNEL_ERROR_INVALID_MESSAGE);
+ SetReadState(READ_STATE_ERROR);
+ } else {
+ // Processed header, now read the body.
+ SetReadState(READ_STATE_READ);
}
} else if (current_read_buffer_.get() == body_read_buffer_.get() &&
static_cast<uint32>(current_read_buffer_->offset()) ==
current_message_size_) {
+ // Store a copy of current_message_size_ since it will be reset by
+ // ProcessBody().
+ uint32 message_size = current_message_size_;
// Full body is read, process the contents.
if (ProcessBody()) {
- read_state_ = READ_STATE_DO_CALLBACK;
+ logger_->LogSocketEventForMessage(
+ channel_id_,
+ proto::MESSAGE_READ,
+ current_message_->namespace_(),
+ base::StringPrintf("Message size: %u", message_size));
+ SetReadState(READ_STATE_DO_CALLBACK);
} else {
- error_state_ = cast_channel::CHANNEL_ERROR_INVALID_MESSAGE;
- read_state_ = READ_STATE_ERROR;
+ SetErrorState(CHANNEL_ERROR_INVALID_MESSAGE);
+ SetReadState(READ_STATE_ERROR);
}
+ } else {
+ // Have not received full header or full body yet; keep reading.
+ SetReadState(READ_STATE_READ);
}
return net::OK;
}
int CastSocket::DoReadCallback() {
- read_state_ = READ_STATE_READ;
+ SetReadState(READ_STATE_READ);
const CastMessage& message = *current_message_;
if (ready_state_ == READY_STATE_CONNECTING) {
if (IsAuthMessage(message)) {
challenge_reply_.reset(new CastMessage(message));
+ logger_->LogSocketEvent(channel_id_, proto::RECEIVED_CHALLENGE_REPLY);
PostTaskToStartConnectLoop(net::OK);
return net::OK;
} else {
- // Expected an auth message, got something else instead. Handle as error.
- read_state_ = READ_STATE_ERROR;
+ SetReadState(READ_STATE_ERROR);
+ SetErrorState(CHANNEL_ERROR_INVALID_MESSAGE);
return net::ERR_INVALID_RESPONSE;
}
}
@@ -710,11 +916,18 @@ int CastSocket::DoReadCallback() {
MessageInfo message_info;
if (!CastMessageToMessageInfo(message, &message_info)) {
current_message_->Clear();
- read_state_ = READ_STATE_ERROR;
+ SetReadState(READ_STATE_ERROR);
+ SetErrorState(CHANNEL_ERROR_INVALID_MESSAGE);
return net::ERR_INVALID_RESPONSE;
}
+
+ logger_->LogSocketEventForMessage(channel_id_,
+ proto::NOTIFY_ON_MESSAGE,
+ message.namespace_(),
+ std::string());
delegate_->OnMessage(this, message_info);
current_message_->Clear();
+
return net::OK;
}
@@ -767,13 +980,14 @@ bool CastSocket::Serialize(const CastMessage& message_proto,
return true;
}
-void CastSocket::CloseWithError(ChannelError error) {
+void CastSocket::CloseWithError() {
DCHECK(CalledOnValidThread());
CloseInternal();
- error_state_ = error;
RunPendingCallbacksOnClose();
- if (delegate_)
- delegate_->OnError(this, error);
+ if (delegate_) {
+ logger_->LogSocketEvent(channel_id_, proto::NOTIFY_ON_ERROR);
+ delegate_->OnError(this, error_state_);
+ }
}
std::string CastSocket::CastUrl() const {
@@ -789,6 +1003,42 @@ base::Timer* CastSocket::GetTimer() {
return connect_timeout_timer_.get();
}
+void CastSocket::SetConnectState(ConnectionState connect_state) {
+ if (connect_state_ != connect_state) {
+ connect_state_ = connect_state;
+ logger_->LogSocketConnectState(channel_id_,
+ ConnectStateToProto(connect_state_));
+ }
+}
+
+void CastSocket::SetReadyState(ReadyState ready_state) {
+ if (ready_state_ != ready_state) {
+ ready_state_ = ready_state;
+ logger_->LogSocketReadyState(channel_id_, ReadyStateToProto(ready_state_));
+ }
+}
+
+void CastSocket::SetErrorState(ChannelError error_state) {
+ if (error_state_ != error_state) {
+ error_state_ = error_state;
+ logger_->LogSocketErrorState(channel_id_, ErrorStateToProto(error_state_));
+ }
+}
+
+void CastSocket::SetReadState(ReadState read_state) {
+ if (read_state_ != read_state) {
+ read_state_ = read_state;
+ logger_->LogSocketReadState(channel_id_, ReadStateToProto(read_state_));
+ }
+}
+
+void CastSocket::SetWriteState(WriteState write_state) {
+ if (write_state_ != write_state) {
+ write_state_ = write_state;
+ logger_->LogSocketWriteState(channel_id_, WriteStateToProto(write_state_));
+ }
+}
+
CastSocket::MessageHeader::MessageHeader() : message_size(0) { }
void CastSocket::MessageHeader::SetMessageSize(size_t size) {
@@ -833,6 +1083,7 @@ bool CastSocket::WriteRequest::SetContent(const CastMessage& message_proto) {
std::string message_data;
if (!Serialize(message_proto, &message_data))
return false;
+ message_namespace = message_proto.namespace_();
io_buffer = new net::DrainableIOBuffer(new net::StringIOBuffer(message_data),
message_data.size());
return true;
diff --git a/extensions/browser/api/cast_channel/cast_socket.h b/extensions/browser/api/cast_channel/cast_socket.h
index 5ff1714..1c12feb 100644
--- a/extensions/browser/api/cast_channel/cast_socket.h
+++ b/extensions/browser/api/cast_channel/cast_socket.h
@@ -36,6 +36,7 @@ namespace core_api {
namespace cast_channel {
class CastMessage;
+class Logger;
// This class implements a channel between Chrome and a Cast device using a TCP
// socket with SSL. The channel may authenticate that the receiver is a genuine
@@ -68,7 +69,8 @@ class CastSocket : public ApiResource {
ChannelAuthType channel_auth,
CastSocket::Delegate* delegate,
net::NetLog* net_log,
- const base::TimeDelta& connect_timeout);
+ const base::TimeDelta& connect_timeout,
+ const scoped_refptr<Logger>& logger);
// Ensures that the socket is closed.
virtual ~CastSocket();
@@ -119,6 +121,36 @@ class CastSocket : public ApiResource {
// It is fine to delete the CastSocket object in |callback|.
virtual void Close(const net::CompletionCallback& callback);
+ // Internal connection states.
+ enum ConnectionState {
+ CONN_STATE_NONE,
+ CONN_STATE_TCP_CONNECT,
+ CONN_STATE_TCP_CONNECT_COMPLETE,
+ CONN_STATE_SSL_CONNECT,
+ CONN_STATE_SSL_CONNECT_COMPLETE,
+ CONN_STATE_AUTH_CHALLENGE_SEND,
+ CONN_STATE_AUTH_CHALLENGE_SEND_COMPLETE,
+ CONN_STATE_AUTH_CHALLENGE_REPLY_COMPLETE,
+ };
+
+ // Internal write states.
+ enum WriteState {
+ WRITE_STATE_NONE,
+ WRITE_STATE_WRITE,
+ WRITE_STATE_WRITE_COMPLETE,
+ WRITE_STATE_DO_CALLBACK,
+ WRITE_STATE_ERROR,
+ };
+
+ // Internal read states.
+ enum ReadState {
+ READ_STATE_NONE,
+ READ_STATE_READ,
+ READ_STATE_READ_COMPLETE,
+ READ_STATE_DO_CALLBACK,
+ READ_STATE_ERROR,
+ };
+
protected:
// Message header struct. If fields are added, be sure to update
// header_size(). Protected to allow use of *_size() methods in unit tests.
@@ -150,36 +182,6 @@ class CastSocket : public ApiResource {
static const char* service_name() { return "CastSocketManager"; }
- // Internal connection states.
- enum ConnectionState {
- CONN_STATE_NONE,
- CONN_STATE_TCP_CONNECT,
- CONN_STATE_TCP_CONNECT_COMPLETE,
- CONN_STATE_SSL_CONNECT,
- CONN_STATE_SSL_CONNECT_COMPLETE,
- CONN_STATE_AUTH_CHALLENGE_SEND,
- CONN_STATE_AUTH_CHALLENGE_SEND_COMPLETE,
- CONN_STATE_AUTH_CHALLENGE_REPLY_COMPLETE,
- };
-
- // Internal write states.
- enum WriteState {
- WRITE_STATE_NONE,
- WRITE_STATE_WRITE,
- WRITE_STATE_WRITE_COMPLETE,
- WRITE_STATE_DO_CALLBACK,
- WRITE_STATE_ERROR,
- };
-
- // Internal read states.
- enum ReadState {
- READ_STATE_NONE,
- READ_STATE_READ,
- READ_STATE_READ_COMPLETE,
- READ_STATE_DO_CALLBACK,
- READ_STATE_ERROR,
- };
-
// Creates an instance of TCPClientSocket.
virtual scoped_ptr<net::TCPClientSocket> CreateTcpSocket();
// Creates an instance of SSLClientSocket with the given underlying |socket|.
@@ -196,7 +198,7 @@ class CastSocket : public ApiResource {
// Invoked by a cancelable closure when connection setup time
// exceeds the interval specified at |connect_timeout|.
- void CancelConnect();
+ void OnConnectTimeout();
/////////////////////////////////////////////////////////////////////////////
// Following methods work together to implement the following flow:
@@ -266,9 +268,8 @@ class CastSocket : public ApiResource {
// Parses the contents of body_read_buffer_ and sets current_message_ to
// the message received.
bool ProcessBody();
- // Closes the socket, sets |error_state_| to |error| and signals the
- // delegate that |error| has occurred.
- void CloseWithError(ChannelError error);
+ // Closes socket, signaling the delegate that |error| has occurred.
+ void CloseWithError();
// Frees resources and cancels pending callbacks. |ready_state_| will be set
// READY_STATE_CLOSED on completion. A no-op if |ready_state_| is already
// READY_STATE_CLOSED.
@@ -276,7 +277,6 @@ class CastSocket : public ApiResource {
// Runs pending callbacks that are passed into us to notify API clients that
// pending operations will fail because the socket has been closed.
void RunPendingCallbacksOnClose();
-
// Serializes the content of message_proto (with a header) to |message_data|.
static bool Serialize(const CastMessage& message_proto,
std::string* message_data);
@@ -285,6 +285,12 @@ class CastSocket : public ApiResource {
virtual base::Timer* GetTimer();
+ void SetConnectState(ConnectionState connect_state);
+ void SetReadyState(ReadyState ready_state);
+ void SetErrorState(ChannelError error_state);
+ void SetReadState(ReadState read_state);
+ void SetWriteState(WriteState write_state);
+
base::ThreadChecker thread_checker_;
// The id of the channel.
@@ -313,6 +319,9 @@ class CastSocket : public ApiResource {
// The NetLog source for this service.
net::NetLog::Source net_log_source_;
+ // Logger used to track multiple CastSockets. Does NOT own this object.
+ scoped_refptr<Logger> logger_;
+
// CertVerifier is owned by us but should be deleted AFTER SSLClientSocket
// since in some cases the destructor of SSLClientSocket may call a method
// to cancel a cert verification request.
@@ -373,6 +382,7 @@ class CastSocket : public ApiResource {
bool SetContent(const CastMessage& message_proto);
net::CompletionCallback callback;
+ std::string message_namespace;
scoped_refptr<net::DrainableIOBuffer> io_buffer;
};
// Queue of pending writes. The message at the front of the queue is the one
diff --git a/extensions/browser/api/cast_channel/cast_socket_unittest.cc b/extensions/browser/api/cast_channel/cast_socket_unittest.cc
index 7a2b724..1068a23 100644
--- a/extensions/browser/api/cast_channel/cast_socket_unittest.cc
+++ b/extensions/browser/api/cast_channel/cast_socket_unittest.cc
@@ -9,9 +9,11 @@
#include "base/run_loop.h"
#include "base/strings/string_number_conversions.h"
#include "base/sys_byteorder.h"
+#include "base/test/simple_test_tick_clock.h"
#include "base/timer/mock_timer.h"
#include "extensions/browser/api/cast_channel/cast_channel.pb.h"
#include "extensions/browser/api/cast_channel/cast_message_util.h"
+#include "extensions/browser/api/cast_channel/logger.h"
#include "net/base/address_list.h"
#include "net/base/capturing_net_log.h"
#include "net/base/net_errors.h"
@@ -143,32 +145,38 @@ class CompleteHandler {
class TestCastSocket : public CastSocket {
public:
- static scoped_ptr<TestCastSocket> Create(
- MockCastSocketDelegate* delegate) {
- return scoped_ptr<TestCastSocket>(
- new TestCastSocket(delegate, CreateIPEndPoint(),
- CHANNEL_AUTH_TYPE_SSL,
- kDistantTimeoutMillis));
+ static scoped_ptr<TestCastSocket> Create(MockCastSocketDelegate* delegate,
+ Logger* logger) {
+ return scoped_ptr<TestCastSocket>(new TestCastSocket(delegate,
+ CreateIPEndPoint(),
+ CHANNEL_AUTH_TYPE_SSL,
+ kDistantTimeoutMillis,
+ logger));
}
static scoped_ptr<TestCastSocket> CreateSecure(
- MockCastSocketDelegate* delegate) {
+ MockCastSocketDelegate* delegate,
+ Logger* logger) {
return scoped_ptr<TestCastSocket>(
- new TestCastSocket(delegate, CreateIPEndPoint(),
+ new TestCastSocket(delegate,
+ CreateIPEndPoint(),
CHANNEL_AUTH_TYPE_SSL_VERIFIED,
- kDistantTimeoutMillis));
+ kDistantTimeoutMillis,
+ logger));
}
explicit TestCastSocket(MockCastSocketDelegate* delegate,
const net::IPEndPoint& ip_endpoint,
ChannelAuthType channel_auth,
- int64 timeout_ms)
+ int64 timeout_ms,
+ Logger* logger)
: CastSocket("abcdefg",
ip_endpoint,
channel_auth,
delegate,
&capturing_net_log_,
- base::TimeDelta::FromMilliseconds(timeout_ms)),
+ base::TimeDelta::FromMilliseconds(timeout_ms),
+ logger),
ip_(ip_endpoint),
connect_index_(0),
extract_cert_result_(true),
@@ -334,7 +342,10 @@ class TestCastSocket : public CastSocket {
class CastSocketTest : public testing::Test {
public:
- CastSocketTest() {}
+ CastSocketTest()
+ : logger_(new Logger(
+ scoped_ptr<base::TickClock>(new base::SimpleTestTickClock),
+ base::TimeTicks())) {}
virtual ~CastSocketTest() {}
virtual void SetUp() OVERRIDE {
@@ -373,11 +384,11 @@ class CastSocketTest : public testing::Test {
}
void CreateCastSocket() {
- socket_ = TestCastSocket::Create(&mock_delegate_);
+ socket_ = TestCastSocket::Create(&mock_delegate_, logger_);
}
void CreateCastSocketSecure() {
- socket_ = TestCastSocket::CreateSecure(&mock_delegate_);
+ socket_ = TestCastSocket::CreateSecure(&mock_delegate_, logger_);
}
// Sets up CastSocket::Connect to succeed.
@@ -403,6 +414,7 @@ class CastSocketTest : public testing::Test {
base::MessageLoop message_loop_;
MockCastSocketDelegate mock_delegate_;
+ scoped_refptr<Logger> logger_;
scoped_ptr<TestCastSocket> socket_;
CompleteHandler handler_;
MessageInfo test_messages_[arraysize(kTestData)];
diff --git a/extensions/browser/api/cast_channel/logger.cc b/extensions/browser/api/cast_channel/logger.cc
new file mode 100644
index 0000000..c1e8c9b
--- /dev/null
+++ b/extensions/browser/api/cast_channel/logger.cc
@@ -0,0 +1,277 @@
+// Copyright 2014 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 "extensions/browser/api/cast_channel/logger.h"
+
+#include "base/strings/string_util.h"
+#include "base/time/tick_clock.h"
+#include "extensions/browser/api/cast_channel/cast_auth_util.h"
+
+namespace extensions {
+namespace core_api {
+namespace cast_channel {
+
+using net::IPEndPoint;
+using proto::AggregatedSocketEvent;
+using proto::EventType;
+using proto::Log;
+using proto::SocketEvent;
+
+namespace {
+
+const char* kInternalNamespacePrefix = "com.google.cast";
+
+proto::ChallengeReplyErrorType ChannegeReplyErrorToProto(
+ AuthResult::ErrorType error_type) {
+ switch (error_type) {
+ case AuthResult::ERROR_NONE:
+ return proto::CHALLENGE_REPLY_ERROR_NONE;
+ case AuthResult::ERROR_PEER_CERT_EMPTY:
+ return proto::CHALLENGE_REPLY_ERROR_PEER_CERT_EMPTY;
+ case AuthResult::ERROR_WRONG_PAYLOAD_TYPE:
+ return proto::CHALLENGE_REPLY_ERROR_WRONG_PAYLOAD_TYPE;
+ case AuthResult::ERROR_NO_PAYLOAD:
+ return proto::CHALLENGE_REPLY_ERROR_NO_PAYLOAD;
+ case AuthResult::ERROR_PAYLOAD_PARSING_FAILED:
+ return proto::CHALLENGE_REPLY_ERROR_PAYLOAD_PARSING_FAILED;
+ case AuthResult::ERROR_MESSAGE_ERROR:
+ return proto::CHALLENGE_REPLY_ERROR_MESSAGE_ERROR;
+ case AuthResult::ERROR_NO_RESPONSE:
+ return proto::CHALLENGE_REPLY_ERROR_NO_RESPONSE;
+ case AuthResult::ERROR_FINGERPRINT_NOT_FOUND:
+ return proto::CHALLENGE_REPLY_ERROR_FINGERPRINT_NOT_FOUND;
+ case AuthResult::ERROR_NSS_CERT_PARSING_FAILED:
+ return proto::CHALLENGE_REPLY_ERROR_NSS_CERT_PARSING_FAILED;
+ case AuthResult::ERROR_NSS_CERT_NOT_SIGNED_BY_TRUSTED_CA:
+ return proto::CHALLENGE_REPLY_ERROR_NSS_CERT_NOT_SIGNED_BY_TRUSTED_CA;
+ case AuthResult::ERROR_NSS_CANNOT_EXTRACT_PUBLIC_KEY:
+ return proto::CHALLENGE_REPLY_ERROR_NSS_CANNOT_EXTRACT_PUBLIC_KEY;
+ case AuthResult::ERROR_NSS_SIGNED_BLOBS_MISMATCH:
+ return proto::CHALLENGE_REPLY_ERROR_NSS_SIGNED_BLOBS_MISMATCH;
+ default:
+ NOTREACHED();
+ return proto::CHALLENGE_REPLY_ERROR_NONE;
+ }
+}
+
+} // namespace
+
+Logger::AggregatedSocketEventLog::AggregatedSocketEventLog() {
+}
+Logger::AggregatedSocketEventLog::~AggregatedSocketEventLog() {
+}
+
+Logger::Logger(scoped_ptr<base::TickClock> clock,
+ base::TimeTicks unix_epoch_time_ticks)
+ : clock_(clock.Pass()),
+ unix_epoch_time_ticks_(unix_epoch_time_ticks),
+ num_evicted_aggregated_socket_events_(0),
+ num_evicted_socket_events_(0) {
+ DCHECK(clock_);
+
+ // Logger may not be necessarily be created on the IO thread, but logging
+ // happens exclusively there.
+ thread_checker_.DetachFromThread();
+}
+
+Logger::~Logger() {
+}
+
+void Logger::LogNewSocketEvent(const CastSocket& cast_socket) {
+ DCHECK(thread_checker_.CalledOnValidThread());
+
+ int channel_id = cast_socket.id();
+ SocketEvent event = CreateEvent(proto::CAST_SOCKET_CREATED);
+ LogSocketEvent(channel_id, event);
+
+ AggregatedSocketEvent& aggregated_socket_event =
+ aggregated_socket_events_.find(channel_id)
+ ->second->aggregated_socket_event;
+ const net::IPAddressNumber& ip = cast_socket.ip_endpoint().address();
+ aggregated_socket_event.set_endpoint_id(ip.back());
+ aggregated_socket_event.set_channel_auth_type(cast_socket.channel_auth() ==
+ CHANNEL_AUTH_TYPE_SSL
+ ? proto::SSL
+ : proto::SSL_VERIFIED);
+}
+
+void Logger::LogSocketEvent(int channel_id, EventType event_type) {
+ DCHECK(thread_checker_.CalledOnValidThread());
+
+ LogSocketEventWithDetails(channel_id, event_type, std::string());
+}
+
+void Logger::LogSocketEventWithDetails(int channel_id,
+ EventType event_type,
+ const std::string& details) {
+ DCHECK(thread_checker_.CalledOnValidThread());
+
+ SocketEvent event = CreateEvent(event_type);
+ if (!details.empty())
+ event.set_details(details);
+
+ LogSocketEvent(channel_id, event);
+}
+
+void Logger::LogSocketEventWithRv(int channel_id,
+ EventType event_type,
+ int rv) {
+ DCHECK(thread_checker_.CalledOnValidThread());
+
+ SocketEvent event = CreateEvent(event_type);
+ event.set_return_value(rv);
+
+ LogSocketEvent(channel_id, event);
+}
+
+void Logger::LogSocketReadyState(int channel_id, proto::ReadyState new_state) {
+ DCHECK(thread_checker_.CalledOnValidThread());
+
+ SocketEvent event = CreateEvent(proto::READY_STATE_CHANGED);
+ event.set_ready_state(new_state);
+
+ LogSocketEvent(channel_id, event);
+}
+
+void Logger::LogSocketConnectState(int channel_id,
+ proto::ConnectionState new_state) {
+ DCHECK(thread_checker_.CalledOnValidThread());
+
+ SocketEvent event = CreateEvent(proto::CONNECTION_STATE_CHANGED);
+ event.set_connection_state(new_state);
+
+ LogSocketEvent(channel_id, event);
+}
+
+void Logger::LogSocketReadState(int channel_id, proto::ReadState new_state) {
+ DCHECK(thread_checker_.CalledOnValidThread());
+
+ SocketEvent event = CreateEvent(proto::READ_STATE_CHANGED);
+ event.set_read_state(new_state);
+
+ LogSocketEvent(channel_id, event);
+}
+
+void Logger::LogSocketWriteState(int channel_id, proto::WriteState new_state) {
+ DCHECK(thread_checker_.CalledOnValidThread());
+
+ SocketEvent event = CreateEvent(proto::WRITE_STATE_CHANGED);
+ event.set_write_state(new_state);
+
+ LogSocketEvent(channel_id, event);
+}
+
+void Logger::LogSocketErrorState(int channel_id, proto::ErrorState new_state) {
+ DCHECK(thread_checker_.CalledOnValidThread());
+
+ SocketEvent event = CreateEvent(proto::ERROR_STATE_CHANGED);
+ event.set_error_state(new_state);
+
+ LogSocketEvent(channel_id, event);
+}
+
+void Logger::LogSocketEventForMessage(int channel_id,
+ EventType event_type,
+ const std::string& message_namespace,
+ const std::string& details) {
+ DCHECK(thread_checker_.CalledOnValidThread());
+
+ SocketEvent event = CreateEvent(event_type);
+ if (StartsWithASCII(message_namespace, kInternalNamespacePrefix, false))
+ event.set_message_namespace(message_namespace);
+ event.set_details(details);
+
+ LogSocketEvent(channel_id, event);
+}
+
+void Logger::LogSocketChallengeReplyEvent(int channel_id,
+ const AuthResult& auth_result) {
+ DCHECK(thread_checker_.CalledOnValidThread());
+
+ SocketEvent event = CreateEvent(proto::AUTH_CHALLENGE_REPLY);
+ event.set_challenge_reply_error_type(
+ ChannegeReplyErrorToProto(auth_result.error_type));
+ if (auth_result.nss_error_code != 0)
+ event.set_return_value(auth_result.nss_error_code);
+
+ LogSocketEvent(channel_id, event);
+}
+
+SocketEvent Logger::CreateEvent(EventType event_type) {
+ SocketEvent event;
+ event.set_type(event_type);
+ event.set_timestamp_micros(clock_->NowTicks().ToInternalValue() +
+ unix_epoch_time_ticks_.ToInternalValue());
+ return event;
+}
+
+void Logger::LogSocketEvent(int channel_id, const SocketEvent& socket_event) {
+ AggregatedSocketEventLogMap::iterator it =
+ aggregated_socket_events_.find(channel_id);
+ if (it == aggregated_socket_events_.end()) {
+ if (aggregated_socket_events_.size() >= kMaxSocketsToLog) {
+ AggregatedSocketEventLogMap::iterator erase_it =
+ aggregated_socket_events_.begin();
+
+ num_evicted_aggregated_socket_events_++;
+ num_evicted_socket_events_ += erase_it->second->socket_events.size();
+
+ aggregated_socket_events_.erase(erase_it);
+ }
+
+ it = aggregated_socket_events_
+ .insert(std::make_pair(
+ channel_id, make_linked_ptr(new AggregatedSocketEventLog)))
+ .first;
+ it->second->aggregated_socket_event.set_id(channel_id);
+ }
+
+ std::deque<proto::SocketEvent>& socket_events = it->second->socket_events;
+ if (socket_events.size() >= kMaxEventsPerSocket) {
+ socket_events.pop_front();
+ num_evicted_socket_events_++;
+ }
+
+ socket_events.push_back(socket_event);
+}
+
+bool Logger::LogToString(std::string* output) const {
+ output->clear();
+
+ Log log;
+ log.set_num_evicted_aggregated_socket_events(
+ num_evicted_aggregated_socket_events_);
+ log.set_num_evicted_socket_events(num_evicted_socket_events_);
+
+ for (AggregatedSocketEventLogMap::const_iterator it =
+ aggregated_socket_events_.begin();
+ it != aggregated_socket_events_.end();
+ ++it) {
+ AggregatedSocketEvent* new_aggregated_socket_event =
+ log.add_aggregated_socket_event();
+ new_aggregated_socket_event->CopyFrom(it->second->aggregated_socket_event);
+
+ const std::deque<SocketEvent>& socket_events = it->second->socket_events;
+ for (std::deque<SocketEvent>::const_iterator socket_event_it =
+ socket_events.begin();
+ socket_event_it != socket_events.end();
+ ++socket_event_it) {
+ SocketEvent* socket_event =
+ new_aggregated_socket_event->add_socket_event();
+ socket_event->CopyFrom(*socket_event_it);
+ }
+ }
+
+ return log.SerializeToString(output);
+}
+
+void Logger::Reset() {
+ aggregated_socket_events_.clear();
+ num_evicted_aggregated_socket_events_ = 0;
+ num_evicted_socket_events_ = 0;
+}
+
+} // namespace cast_channel
+} // namespace api
+} // namespace extensions
diff --git a/extensions/browser/api/cast_channel/logger.h b/extensions/browser/api/cast_channel/logger.h
new file mode 100644
index 0000000..fc301ca
--- /dev/null
+++ b/extensions/browser/api/cast_channel/logger.h
@@ -0,0 +1,132 @@
+// Copyright 2014 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.
+
+#ifndef EXTENSIONS_BROWSER_API_CAST_CHANNEL_LOGGER_H_
+#define EXTENSIONS_BROWSER_API_CAST_CHANNEL_LOGGER_H_
+
+#include <deque>
+#include <map>
+
+#include "base/basictypes.h"
+#include "base/memory/linked_ptr.h"
+#include "base/memory/scoped_ptr.h"
+#include "base/threading/thread_checker.h"
+#include "extensions/browser/api/cast_channel/cast_socket.h"
+#include "extensions/browser/api/cast_channel/logging.pb.h"
+#include "net/base/ip_endpoint.h"
+
+namespace base {
+class TickClock;
+}
+
+namespace extensions {
+namespace core_api {
+namespace cast_channel {
+
+struct AuthResult;
+
+static const int kMaxSocketsToLog = 50;
+static const int kMaxEventsPerSocket = 2000;
+
+// Logs information of each channel and sockets and exports the log as
+// a blob. Logger is done on the IO thread.
+class Logger : public base::RefCounted<Logger> {
+ public:
+ // |clock|: Clock used for generating timestamps for the events. Owned by
+ // this class.
+ // |unix_epoch_time_ticks|: The TimeTicks that corresponds to Unix epoch.
+ Logger(scoped_ptr<base::TickClock> clock,
+ base::TimeTicks unix_epoch_time_ticks);
+
+ // For newly created sockets. Will create an event and log a
+ // CAST_SOCKET_CREATED event.
+ void LogNewSocketEvent(const CastSocket& cast_socket);
+
+ void LogSocketEvent(int channel_id, proto::EventType event_type);
+ void LogSocketEventWithDetails(int channel_id,
+ proto::EventType event_type,
+ const std::string& details);
+
+ // For events that involves socket / crypto operations that returns a value.
+ void LogSocketEventWithRv(int channel_id,
+ proto::EventType event_type,
+ int rv);
+
+ // For *_STATE_CHANGED events.
+ void LogSocketReadyState(int channel_id, proto::ReadyState new_state);
+ void LogSocketConnectState(int channel_id, proto::ConnectionState new_state);
+ void LogSocketReadState(int channel_id, proto::ReadState new_state);
+ void LogSocketWriteState(int channel_id, proto::WriteState new_state);
+ void LogSocketErrorState(int channel_id, proto::ErrorState new_state);
+
+ // For AUTH_CHALLENGE_REPLY event.
+ void LogSocketChallengeReplyEvent(int channel_id,
+ const AuthResult& auth_result);
+
+ void LogSocketEventForMessage(int channel_id,
+ proto::EventType event_type,
+ const std::string& message_namespace,
+ const std::string& details);
+
+ // Assembles logs collected so far and return it as a serialized Log proto.
+ // |output|: Where serialized contents will be assigned to.
+ // Returns true if serialization is successful.
+ // Contents in |output| is valid only if function returns true.
+ // TODO(imcheng): Add compression.
+ bool LogToString(std::string* output) const;
+
+ // Clears the internal map.
+ void Reset();
+
+ private:
+ friend class base::RefCounted<Logger>;
+ ~Logger();
+
+ struct AggregatedSocketEventLog {
+ public:
+ AggregatedSocketEventLog();
+ ~AggregatedSocketEventLog();
+
+ // Partially constructed AggregatedSocketEvent proto populated by Logger.
+ // Contains top level info such as channel ID, IP end point and channel
+ // auth type.
+ proto::AggregatedSocketEvent aggregated_socket_event;
+ // Events to be assigned to the AggregatedSocketEvent proto. Contains the
+ // most recent |kMaxEventsPerSocket| entries. The oldest events are
+ // evicted as new events are logged.
+ std::deque<proto::SocketEvent> socket_events;
+ };
+
+ typedef std::map<int, linked_ptr<AggregatedSocketEventLog> >
+ AggregatedSocketEventLogMap;
+
+ // Returns a SocketEvent proto with common fields (EventType, timestamp)
+ // populated.
+ proto::SocketEvent CreateEvent(proto::EventType event_type);
+
+ // Records |event| associated with |channel_id|.
+ // If the internal map is already logging maximum number of sockets and this
+ // is a new socket, the socket with the smallest channel id will be discarded.
+ // Returns a pointer to the Event proto with |event_type| and
+ // timestamp populated.
+ void LogSocketEvent(int channel_id, const proto::SocketEvent& socket_event);
+
+ scoped_ptr<base::TickClock> clock_;
+ AggregatedSocketEventLogMap aggregated_socket_events_;
+ base::TimeTicks unix_epoch_time_ticks_;
+
+ // Number of socket / event entries evicted by the logger due to size
+ // constraints.
+ int num_evicted_aggregated_socket_events_;
+ int num_evicted_socket_events_;
+
+ base::ThreadChecker thread_checker_;
+
+ DISALLOW_COPY_AND_ASSIGN(Logger);
+};
+} // namespace cast_channel
+} // namespace api
+} // namespace extensions
+
+#endif // EXTENSIONS_BROWSER_API_CAST_CHANNEL_LOGGER_H_
diff --git a/extensions/browser/api/cast_channel/logger_unittest.cc b/extensions/browser/api/cast_channel/logger_unittest.cc
new file mode 100644
index 0000000..d1ec5fc
--- /dev/null
+++ b/extensions/browser/api/cast_channel/logger_unittest.cc
@@ -0,0 +1,196 @@
+// Copyright 2014 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 "base/test/simple_test_tick_clock.h"
+#include "extensions/browser/api/cast_channel/cast_auth_util.h"
+#include "extensions/browser/api/cast_channel/logger.h"
+#include "testing/gtest/include/gtest/gtest.h"
+
+namespace extensions {
+namespace core_api {
+namespace cast_channel {
+
+using proto::AggregatedSocketEvent;
+using proto::EventType;
+using proto::Log;
+using proto::SocketEvent;
+
+class CastChannelLoggerTest : public testing::Test {
+ public:
+ // |logger_| will take ownership of |clock_|.
+ CastChannelLoggerTest()
+ : clock_(new base::SimpleTestTickClock),
+ logger_(new Logger(scoped_ptr<base::TickClock>(clock_),
+ base::TimeTicks())) {}
+ virtual ~CastChannelLoggerTest() {}
+
+ protected:
+ base::SimpleTestTickClock* clock_;
+ scoped_refptr<Logger> logger_;
+};
+
+TEST_F(CastChannelLoggerTest, BasicLogging) {
+ logger_->LogSocketEvent(1, EventType::CAST_SOCKET_CREATED);
+ clock_->Advance(base::TimeDelta::FromMicroseconds(1));
+ logger_->LogSocketEventWithDetails(
+ 1, EventType::TCP_SOCKET_CONNECT, "TCP socket");
+ clock_->Advance(base::TimeDelta::FromMicroseconds(1));
+ logger_->LogSocketEvent(2, EventType::CAST_SOCKET_CREATED);
+ clock_->Advance(base::TimeDelta::FromMicroseconds(1));
+ logger_->LogSocketEventWithRv(1, EventType::SSL_SOCKET_CONNECT, -1);
+ clock_->Advance(base::TimeDelta::FromMicroseconds(1));
+ logger_->LogSocketEventForMessage(
+ 2, EventType::MESSAGE_ENQUEUED, "foo_namespace", "details");
+ clock_->Advance(base::TimeDelta::FromMicroseconds(1));
+
+ AuthResult auth_result =
+ AuthResult::Create("No response", AuthResult::ERROR_NO_RESPONSE);
+
+ logger_->LogSocketChallengeReplyEvent(2, auth_result);
+ clock_->Advance(base::TimeDelta::FromMicroseconds(1));
+
+ auth_result = AuthResult::CreateWithNSSError(
+ "Parsing failed", AuthResult::ERROR_NSS_CERT_PARSING_FAILED, 4);
+ logger_->LogSocketChallengeReplyEvent(2, auth_result);
+
+ std::string output;
+ bool success = logger_->LogToString(&output);
+ ASSERT_TRUE(success);
+
+ Log log;
+ success = log.ParseFromString(output);
+ ASSERT_TRUE(success);
+
+ ASSERT_EQ(2, log.aggregated_socket_event_size());
+ {
+ const AggregatedSocketEvent& aggregated_socket_event =
+ log.aggregated_socket_event(0);
+ EXPECT_EQ(1, aggregated_socket_event.id());
+ EXPECT_EQ(3, aggregated_socket_event.socket_event_size());
+ {
+ const SocketEvent& event = aggregated_socket_event.socket_event(0);
+ EXPECT_EQ(EventType::CAST_SOCKET_CREATED, event.type());
+ EXPECT_EQ(0, event.timestamp_micros());
+ }
+ {
+ const SocketEvent& event = aggregated_socket_event.socket_event(1);
+ EXPECT_EQ(EventType::TCP_SOCKET_CONNECT, event.type());
+ EXPECT_EQ(1, event.timestamp_micros());
+ EXPECT_EQ("TCP socket", event.details());
+ }
+ {
+ const SocketEvent& event = aggregated_socket_event.socket_event(2);
+ EXPECT_EQ(EventType::SSL_SOCKET_CONNECT, event.type());
+ EXPECT_EQ(3, event.timestamp_micros());
+ EXPECT_EQ(-1, event.return_value());
+ }
+ }
+ {
+ const AggregatedSocketEvent& aggregated_socket_event =
+ log.aggregated_socket_event(1);
+ EXPECT_EQ(2, aggregated_socket_event.id());
+ EXPECT_EQ(4, aggregated_socket_event.socket_event_size());
+ {
+ const SocketEvent& event = aggregated_socket_event.socket_event(0);
+ EXPECT_EQ(EventType::CAST_SOCKET_CREATED, event.type());
+ EXPECT_EQ(2, event.timestamp_micros());
+ }
+ {
+ const SocketEvent& event = aggregated_socket_event.socket_event(1);
+ EXPECT_EQ(EventType::MESSAGE_ENQUEUED, event.type());
+ EXPECT_EQ(4, event.timestamp_micros());
+ EXPECT_FALSE(event.has_message_namespace());
+ EXPECT_EQ("details", event.details());
+ }
+ {
+ const SocketEvent& event = aggregated_socket_event.socket_event(2);
+ EXPECT_EQ(EventType::AUTH_CHALLENGE_REPLY, event.type());
+ EXPECT_EQ(5, event.timestamp_micros());
+ EXPECT_EQ(proto::CHALLENGE_REPLY_ERROR_NO_RESPONSE,
+ event.challenge_reply_error_type());
+ EXPECT_FALSE(event.has_return_value());
+ }
+ {
+ const SocketEvent& event = aggregated_socket_event.socket_event(3);
+ EXPECT_EQ(EventType::AUTH_CHALLENGE_REPLY, event.type());
+ EXPECT_EQ(6, event.timestamp_micros());
+ EXPECT_EQ(proto::CHALLENGE_REPLY_ERROR_NSS_CERT_PARSING_FAILED,
+ event.challenge_reply_error_type());
+ EXPECT_EQ(4, event.return_value());
+ }
+ }
+}
+
+TEST_F(CastChannelLoggerTest, TooManySockets) {
+ for (int i = 0; i < kMaxSocketsToLog + 5; i++) {
+ logger_->LogSocketEvent(i, EventType::CAST_SOCKET_CREATED);
+ }
+
+ std::string output;
+ bool success = logger_->LogToString(&output);
+ ASSERT_TRUE(success);
+
+ Log log;
+ success = log.ParseFromString(output);
+ ASSERT_TRUE(success);
+
+ ASSERT_EQ(kMaxSocketsToLog, log.aggregated_socket_event_size());
+ EXPECT_EQ(5, log.num_evicted_aggregated_socket_events());
+ EXPECT_EQ(5, log.num_evicted_socket_events());
+
+ const AggregatedSocketEvent& aggregated_socket_event =
+ log.aggregated_socket_event(0);
+ EXPECT_EQ(5, aggregated_socket_event.id());
+}
+
+TEST_F(CastChannelLoggerTest, TooManyEvents) {
+ for (int i = 0; i < kMaxEventsPerSocket + 5; i++) {
+ logger_->LogSocketEvent(1, EventType::CAST_SOCKET_CREATED);
+ clock_->Advance(base::TimeDelta::FromMicroseconds(1));
+ }
+
+ std::string output;
+ bool success = logger_->LogToString(&output);
+ ASSERT_TRUE(success);
+
+ Log log;
+ success = log.ParseFromString(output);
+ ASSERT_TRUE(success);
+
+ ASSERT_EQ(1, log.aggregated_socket_event_size());
+ EXPECT_EQ(0, log.num_evicted_aggregated_socket_events());
+ EXPECT_EQ(5, log.num_evicted_socket_events());
+
+ const AggregatedSocketEvent& aggregated_socket_event =
+ log.aggregated_socket_event(0);
+ ASSERT_EQ(kMaxEventsPerSocket, aggregated_socket_event.socket_event_size());
+ EXPECT_EQ(5, aggregated_socket_event.socket_event(0).timestamp_micros());
+}
+
+TEST_F(CastChannelLoggerTest, Reset) {
+ logger_->LogSocketEvent(1, EventType::CAST_SOCKET_CREATED);
+
+ std::string output;
+ bool success = logger_->LogToString(&output);
+ ASSERT_TRUE(success);
+
+ Log log;
+ success = log.ParseFromString(output);
+ ASSERT_TRUE(success);
+
+ EXPECT_EQ(1, log.aggregated_socket_event_size());
+
+ logger_->Reset();
+
+ success = logger_->LogToString(&output);
+ ASSERT_TRUE(success);
+ success = log.ParseFromString(output);
+ ASSERT_TRUE(success);
+
+ EXPECT_EQ(0, log.aggregated_socket_event_size());
+}
+
+} // namespace cast_channel
+} // namespace api
+} // namespace extensions
diff --git a/extensions/browser/api/cast_channel/logging.proto b/extensions/browser/api/cast_channel/logging.proto
new file mode 100644
index 0000000..57bd461
--- /dev/null
+++ b/extensions/browser/api/cast_channel/logging.proto
@@ -0,0 +1,147 @@
+// Copyright 2014 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.
+
+syntax = "proto2";
+
+option optimize_for = LITE_RUNTIME;
+
+package extensions.core_api.cast_channel.proto;
+
+enum EventType {
+ CAST_SOCKET_CREATED = 1;
+ READY_STATE_CHANGED = 2;
+ CONNECTION_STATE_CHANGED = 3;
+ READ_STATE_CHANGED = 4;
+ WRITE_STATE_CHANGED = 5;
+ ERROR_STATE_CHANGED = 6;
+ CONNECT_FAILED = 7;
+ TCP_SOCKET_CONNECT = 8; // Logged with RV.
+ TCP_SOCKET_SET_KEEP_ALIVE = 9;
+ SSL_CERT_WHITELISTED = 10;
+ SSL_SOCKET_CONNECT = 11; // Logged with RV.
+ SSL_INFO_OBTAINED = 12;
+ DER_ENCODED_CERT_OBTAIN = 13; // Logged with RV.
+ RECEIVED_CHALLENGE_REPLY = 14;
+ AUTH_CHALLENGE_REPLY = 15;
+ CONNECT_TIMED_OUT = 16;
+ SEND_MESSAGE_FAILED = 17;
+ MESSAGE_ENQUEUED = 18; // Message
+ SOCKET_WRITE = 19; // Logged with RV.
+ MESSAGE_WRITTEN = 20; // Message
+ SOCKET_READ = 21; // Logged with RV.
+ MESSAGE_READ = 22; // Message
+ NOTIFY_ON_MESSAGE = 23; // Message
+ NOTIFY_ON_ERROR = 24;
+ SOCKET_CLOSED = 25;
+}
+
+enum ChannelAuth {
+ // SSL over TCP.
+ SSL = 1;
+ // SSL over TCP with challenge and receiver signature verification.
+ SSL_VERIFIED = 2;
+}
+
+enum ReadyState {
+ READY_STATE_NONE = 1;
+ READY_STATE_CONNECTING = 2;
+ READY_STATE_OPEN = 3;
+ READY_STATE_CLOSING = 4;
+ READY_STATE_CLOSED = 5;
+}
+
+enum ConnectionState {
+ CONN_STATE_NONE = 1;
+ CONN_STATE_TCP_CONNECT = 2;
+ CONN_STATE_TCP_CONNECT_COMPLETE = 3;
+ CONN_STATE_SSL_CONNECT = 4;
+ CONN_STATE_SSL_CONNECT_COMPLETE = 5;
+ CONN_STATE_AUTH_CHALLENGE_SEND = 6;
+ CONN_STATE_AUTH_CHALLENGE_SEND_COMPLETE = 7;
+ CONN_STATE_AUTH_CHALLENGE_REPLY_COMPLETE = 8;
+}
+
+enum ReadState {
+ READ_STATE_NONE = 1;
+ READ_STATE_READ = 2;
+ READ_STATE_READ_COMPLETE = 3;
+ READ_STATE_DO_CALLBACK = 4;
+ READ_STATE_ERROR = 5;
+}
+
+enum WriteState {
+ WRITE_STATE_NONE = 1;
+ WRITE_STATE_WRITE = 2;
+ WRITE_STATE_WRITE_COMPLETE = 3;
+ WRITE_STATE_DO_CALLBACK = 4;
+ WRITE_STATE_ERROR = 5;
+}
+
+enum ErrorState {
+ CHANNEL_ERROR_NONE = 1;
+ CHANNEL_ERROR_CHANNEL_NOT_OPEN = 2;
+ CHANNEL_ERROR_AUTHENTICATION_ERROR = 3;
+ CHANNEL_ERROR_CONNECT_ERROR = 4;
+ CHANNEL_ERROR_SOCKET_ERROR = 5;
+ CHANNEL_ERROR_TRANSPORT_ERROR = 6;
+ CHANNEL_ERROR_INVALID_MESSAGE = 7;
+ CHANNEL_ERROR_INVALID_CHANNEL_ID = 8;
+ CHANNEL_ERROR_CONNECT_TIMEOUT = 9;
+ CHANNEL_ERROR_UNKNOWN = 10;
+}
+
+enum ChallengeReplyErrorType {
+ CHALLENGE_REPLY_ERROR_NONE = 1;
+ CHALLENGE_REPLY_ERROR_PEER_CERT_EMPTY = 2;
+ CHALLENGE_REPLY_ERROR_WRONG_PAYLOAD_TYPE = 3;
+ CHALLENGE_REPLY_ERROR_NO_PAYLOAD = 4;
+ CHALLENGE_REPLY_ERROR_PAYLOAD_PARSING_FAILED = 5;
+ CHALLENGE_REPLY_ERROR_MESSAGE_ERROR = 6;
+ CHALLENGE_REPLY_ERROR_NO_RESPONSE = 7;
+ CHALLENGE_REPLY_ERROR_FINGERPRINT_NOT_FOUND = 8;
+ CHALLENGE_REPLY_ERROR_NSS_CERT_PARSING_FAILED = 9;
+ CHALLENGE_REPLY_ERROR_NSS_CERT_NOT_SIGNED_BY_TRUSTED_CA = 10;
+ CHALLENGE_REPLY_ERROR_NSS_CANNOT_EXTRACT_PUBLIC_KEY = 11;
+ CHALLENGE_REPLY_ERROR_NSS_SIGNED_BLOBS_MISMATCH = 12;
+}
+
+message SocketEvent {
+ // Required
+ optional EventType type = 1;
+ optional int64 timestamp_micros = 2;
+
+ optional string details = 3;
+
+ optional int32 return_value = 4;
+
+ optional string message_namespace = 5;
+
+ optional ReadyState ready_state = 6;
+ optional ConnectionState connection_state = 7;
+ optional ReadState read_state = 8;
+ optional WriteState write_state = 9;
+ optional ErrorState error_state = 10;
+
+ optional ChallengeReplyErrorType challenge_reply_error_type = 11;
+}
+
+message AggregatedSocketEvent {
+ optional int32 id = 1;
+ optional int32 endpoint_id = 2;
+ optional ChannelAuth channel_auth_type = 3;
+ repeated SocketEvent socket_event = 4;
+}
+
+message Log {
+ // Each AggregatedSocketEvent represents events recorded for a socket.
+ repeated AggregatedSocketEvent aggregated_socket_event = 1;
+
+ // Number of socket log entries evicted by the logger due to size constraints.
+ optional int32 num_evicted_aggregated_socket_events = 2;
+
+ // Number of event log entries evicted by the logger due to size constraints.
+ optional int32 num_evicted_socket_events = 3;
+
+ // TODO(imcheng): Add other stats, such as bytes read/written across sockets.
+}