OLD | NEW |
1 // Copyright 2014 The Chromium Authors. All rights reserved. | 1 // Copyright 2014 The Chromium Authors. All rights reserved. |
2 // Use of this source code is governed by a BSD-style license that can be | 2 // Use of this source code is governed by a BSD-style license that can be |
3 // found in the LICENSE file. | 3 // found in the LICENSE file. |
4 | 4 |
5 #include <stddef.h> | 5 #include <stddef.h> |
6 #include <stdint.h> | 6 #include <stdint.h> |
7 | 7 |
8 #include <string> | 8 #include <string> |
9 | 9 |
10 #include "base/test/simple_test_clock.h" | |
11 #include "extensions/browser/api/cast_channel/cast_auth_util.h" | 10 #include "extensions/browser/api/cast_channel/cast_auth_util.h" |
12 #include "extensions/browser/api/cast_channel/logger.h" | 11 #include "extensions/browser/api/cast_channel/logger.h" |
13 #include "extensions/browser/api/cast_channel/logger_util.h" | |
14 #include "net/base/net_errors.h" | 12 #include "net/base/net_errors.h" |
15 #include "testing/gtest/include/gtest/gtest.h" | 13 #include "testing/gtest/include/gtest/gtest.h" |
16 #include "third_party/zlib/zlib.h" | |
17 | 14 |
18 namespace extensions { | 15 namespace extensions { |
19 namespace api { | 16 namespace api { |
20 namespace cast_channel { | 17 namespace cast_channel { |
21 | 18 |
22 using proto::AggregatedSocketEvent; | |
23 using proto::EventType; | 19 using proto::EventType; |
24 using proto::Log; | 20 using proto::Log; |
25 using proto::SocketEvent; | 21 using proto::SocketEvent; |
26 | 22 |
27 class CastChannelLoggerTest : public testing::Test { | 23 TEST(CastChannelLoggerTest, LogLastErrorEvents) { |
28 public: | 24 scoped_refptr<Logger> logger(new Logger()); |
29 // |logger_| will take ownership of |clock_|. | |
30 CastChannelLoggerTest() | |
31 : clock_(new base::SimpleTestClock), | |
32 logger_( | |
33 new Logger(std::unique_ptr<base::Clock>(clock_), base::Time())) {} | |
34 ~CastChannelLoggerTest() override {} | |
35 | 25 |
36 bool Uncompress(const char* input, int length, std::string* output) { | 26 // Net return value is set to an error |
37 z_stream stream = {0}; | 27 logger->LogSocketEventWithRv(1, EventType::TCP_SOCKET_CONNECT, |
| 28 net::ERR_CONNECTION_FAILED); |
38 | 29 |
39 stream.next_in = reinterpret_cast<uint8_t*>(const_cast<char*>(input)); | 30 LastErrors last_errors = logger->GetLastErrors(1); |
40 stream.avail_in = length; | |
41 stream.next_out = reinterpret_cast<uint8_t*>(&(*output)[0]); | |
42 stream.avail_out = output->size(); | |
43 | |
44 bool success = false; | |
45 while (stream.avail_in > 0 && stream.avail_out > 0) { | |
46 // 16 is added to read in gzip format. | |
47 int result = inflateInit2(&stream, MAX_WBITS + 16); | |
48 DCHECK_EQ(Z_OK, result); | |
49 | |
50 result = inflate(&stream, Z_FINISH); | |
51 success = (result == Z_STREAM_END); | |
52 if (!success) { | |
53 DVLOG(2) << "inflate() failed. Result: " << result; | |
54 break; | |
55 } | |
56 | |
57 result = inflateEnd(&stream); | |
58 DCHECK(result == Z_OK); | |
59 } | |
60 | |
61 if (stream.avail_in == 0) { | |
62 success = true; | |
63 output->resize(output->size() - stream.avail_out); | |
64 } | |
65 return success; | |
66 } | |
67 | |
68 std::unique_ptr<Log> GetLog() { | |
69 size_t length = 0; | |
70 std::unique_ptr<char[]> output = logger_->GetLogs(&length); | |
71 if (!output.get()) | |
72 return std::unique_ptr<Log>(); | |
73 | |
74 // 20kb should be enough for test purposes. | |
75 std::string uncompressed(20000, 0); | |
76 if (!Uncompress(output.get(), length, &uncompressed)) | |
77 return std::unique_ptr<Log>(); | |
78 | |
79 std::unique_ptr<Log> log(new Log); | |
80 if (!log->ParseFromString(uncompressed)) | |
81 return std::unique_ptr<Log>(); | |
82 | |
83 return log; | |
84 } | |
85 | |
86 protected: | |
87 base::SimpleTestClock* clock_; | |
88 scoped_refptr<Logger> logger_; | |
89 }; | |
90 | |
91 TEST_F(CastChannelLoggerTest, BasicLogging) { | |
92 logger_->LogSocketEvent(1, EventType::CAST_SOCKET_CREATED); | |
93 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
94 logger_->LogSocketEventWithDetails( | |
95 1, EventType::TCP_SOCKET_CONNECT, "TCP socket"); | |
96 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
97 logger_->LogSocketEvent(2, EventType::CAST_SOCKET_CREATED); | |
98 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
99 logger_->LogSocketEventWithRv(1, EventType::SSL_SOCKET_CONNECT, -1); | |
100 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
101 logger_->LogSocketEventForMessage( | |
102 2, EventType::MESSAGE_ENQUEUED, "foo_namespace", "details"); | |
103 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
104 | |
105 AuthResult auth_result = AuthResult::CreateWithParseError( | |
106 "No response", AuthResult::ERROR_NO_RESPONSE); | |
107 | |
108 logger_->LogSocketChallengeReplyEvent(2, auth_result); | |
109 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
110 | |
111 auth_result = | |
112 AuthResult("Parsing failed", AuthResult::ERROR_CERT_PARSING_FAILED); | |
113 logger_->LogSocketChallengeReplyEvent(2, auth_result); | |
114 | |
115 LastErrors last_errors = logger_->GetLastErrors(2); | |
116 EXPECT_EQ(last_errors.event_type, proto::AUTH_CHALLENGE_REPLY); | |
117 EXPECT_EQ(last_errors.net_return_value, net::OK); | |
118 EXPECT_EQ(last_errors.challenge_reply_error_type, | |
119 proto::CHALLENGE_REPLY_ERROR_CERT_PARSING_FAILED); | |
120 | |
121 std::unique_ptr<Log> log = GetLog(); | |
122 ASSERT_TRUE(log); | |
123 | |
124 ASSERT_EQ(2, log->aggregated_socket_event_size()); | |
125 { | |
126 const AggregatedSocketEvent& aggregated_socket_event = | |
127 log->aggregated_socket_event(0); | |
128 EXPECT_EQ(1, aggregated_socket_event.id()); | |
129 EXPECT_EQ(3, aggregated_socket_event.socket_event_size()); | |
130 { | |
131 const SocketEvent& event = aggregated_socket_event.socket_event(0); | |
132 EXPECT_EQ(EventType::CAST_SOCKET_CREATED, event.type()); | |
133 EXPECT_EQ(0, event.timestamp_micros()); | |
134 } | |
135 { | |
136 const SocketEvent& event = aggregated_socket_event.socket_event(1); | |
137 EXPECT_EQ(EventType::TCP_SOCKET_CONNECT, event.type()); | |
138 EXPECT_EQ(1, event.timestamp_micros()); | |
139 EXPECT_EQ("TCP socket", event.details()); | |
140 } | |
141 { | |
142 const SocketEvent& event = aggregated_socket_event.socket_event(2); | |
143 EXPECT_EQ(EventType::SSL_SOCKET_CONNECT, event.type()); | |
144 EXPECT_EQ(3, event.timestamp_micros()); | |
145 EXPECT_EQ(-1, event.net_return_value()); | |
146 } | |
147 } | |
148 { | |
149 const AggregatedSocketEvent& aggregated_socket_event = | |
150 log->aggregated_socket_event(1); | |
151 EXPECT_EQ(2, aggregated_socket_event.id()); | |
152 EXPECT_EQ(4, aggregated_socket_event.socket_event_size()); | |
153 { | |
154 const SocketEvent& event = aggregated_socket_event.socket_event(0); | |
155 EXPECT_EQ(EventType::CAST_SOCKET_CREATED, event.type()); | |
156 EXPECT_EQ(2, event.timestamp_micros()); | |
157 } | |
158 { | |
159 const SocketEvent& event = aggregated_socket_event.socket_event(1); | |
160 EXPECT_EQ(EventType::MESSAGE_ENQUEUED, event.type()); | |
161 EXPECT_EQ(4, event.timestamp_micros()); | |
162 EXPECT_FALSE(event.has_message_namespace()); | |
163 EXPECT_EQ("details", event.details()); | |
164 } | |
165 { | |
166 const SocketEvent& event = aggregated_socket_event.socket_event(2); | |
167 EXPECT_EQ(EventType::AUTH_CHALLENGE_REPLY, event.type()); | |
168 EXPECT_EQ(5, event.timestamp_micros()); | |
169 EXPECT_EQ(proto::CHALLENGE_REPLY_ERROR_NO_RESPONSE, | |
170 event.challenge_reply_error_type()); | |
171 EXPECT_FALSE(event.has_net_return_value()); | |
172 EXPECT_FALSE(event.has_nss_error_code()); | |
173 } | |
174 { | |
175 const SocketEvent& event = aggregated_socket_event.socket_event(3); | |
176 EXPECT_EQ(EventType::AUTH_CHALLENGE_REPLY, event.type()); | |
177 EXPECT_EQ(6, event.timestamp_micros()); | |
178 EXPECT_EQ(proto::CHALLENGE_REPLY_ERROR_CERT_PARSING_FAILED, | |
179 event.challenge_reply_error_type()); | |
180 EXPECT_FALSE(event.has_net_return_value()); | |
181 EXPECT_FALSE(event.has_nss_error_code()); | |
182 } | |
183 } | |
184 } | |
185 | |
186 TEST_F(CastChannelLoggerTest, LogLastErrorEvents) { | |
187 // Net return value is set to an error | |
188 logger_->LogSocketEventWithRv( | |
189 1, EventType::TCP_SOCKET_CONNECT, net::ERR_CONNECTION_FAILED); | |
190 | |
191 LastErrors last_errors = logger_->GetLastErrors(1); | |
192 EXPECT_EQ(last_errors.event_type, proto::TCP_SOCKET_CONNECT); | 31 EXPECT_EQ(last_errors.event_type, proto::TCP_SOCKET_CONNECT); |
193 EXPECT_EQ(last_errors.net_return_value, net::ERR_CONNECTION_FAILED); | 32 EXPECT_EQ(last_errors.net_return_value, net::ERR_CONNECTION_FAILED); |
194 | 33 |
195 // Challenge reply error set | 34 // Challenge reply error set |
196 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
197 AuthResult auth_result = AuthResult::CreateWithParseError( | 35 AuthResult auth_result = AuthResult::CreateWithParseError( |
198 "Some error", AuthResult::ErrorType::ERROR_PEER_CERT_EMPTY); | 36 "Some error", AuthResult::ErrorType::ERROR_PEER_CERT_EMPTY); |
199 | 37 |
200 logger_->LogSocketChallengeReplyEvent(2, auth_result); | 38 logger->LogSocketChallengeReplyEvent(2, auth_result); |
201 last_errors = logger_->GetLastErrors(2); | 39 last_errors = logger->GetLastErrors(2); |
202 EXPECT_EQ(last_errors.event_type, proto::AUTH_CHALLENGE_REPLY); | 40 EXPECT_EQ(last_errors.event_type, proto::AUTH_CHALLENGE_REPLY); |
203 EXPECT_EQ(last_errors.challenge_reply_error_type, | 41 EXPECT_EQ(last_errors.challenge_reply_error_type, |
204 proto::CHALLENGE_REPLY_ERROR_PEER_CERT_EMPTY); | 42 proto::CHALLENGE_REPLY_ERROR_PEER_CERT_EMPTY); |
205 | 43 |
206 // Logging a non-error event does not set the LastErrors for the channel. | 44 // Logging a non-error event does not set the LastErrors for the channel. |
207 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | 45 logger->LogSocketEventWithRv(3, EventType::TCP_SOCKET_CONNECT, net::OK); |
208 logger_->LogSocketEventWithRv(3, EventType::TCP_SOCKET_CONNECT, net::OK); | 46 last_errors = logger->GetLastErrors(3); |
209 last_errors = logger_->GetLastErrors(3); | |
210 EXPECT_EQ(last_errors.event_type, proto::EVENT_TYPE_UNKNOWN); | 47 EXPECT_EQ(last_errors.event_type, proto::EVENT_TYPE_UNKNOWN); |
211 EXPECT_EQ(last_errors.net_return_value, net::OK); | 48 EXPECT_EQ(last_errors.net_return_value, net::OK); |
212 EXPECT_EQ(last_errors.challenge_reply_error_type, | 49 EXPECT_EQ(last_errors.challenge_reply_error_type, |
213 proto::CHALLENGE_REPLY_ERROR_NONE); | 50 proto::CHALLENGE_REPLY_ERROR_NONE); |
214 | 51 |
215 // Now log a challenge reply error. LastErrors will be set. | 52 // Now log a challenge reply error. LastErrors will be set. |
216 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
217 auth_result = | 53 auth_result = |
218 AuthResult("Some error failed", AuthResult::ERROR_WRONG_PAYLOAD_TYPE); | 54 AuthResult("Some error failed", AuthResult::ERROR_WRONG_PAYLOAD_TYPE); |
219 logger_->LogSocketChallengeReplyEvent(3, auth_result); | 55 logger->LogSocketChallengeReplyEvent(3, auth_result); |
220 last_errors = logger_->GetLastErrors(3); | 56 last_errors = logger->GetLastErrors(3); |
221 EXPECT_EQ(last_errors.event_type, proto::AUTH_CHALLENGE_REPLY); | 57 EXPECT_EQ(last_errors.event_type, proto::AUTH_CHALLENGE_REPLY); |
222 EXPECT_EQ(last_errors.challenge_reply_error_type, | 58 EXPECT_EQ(last_errors.challenge_reply_error_type, |
223 proto::CHALLENGE_REPLY_ERROR_WRONG_PAYLOAD_TYPE); | 59 proto::CHALLENGE_REPLY_ERROR_WRONG_PAYLOAD_TYPE); |
224 | 60 |
225 // Logging a non-error event does not change the LastErrors for the channel. | 61 // Logging a non-error event does not change the LastErrors for the channel. |
226 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | 62 logger->LogSocketEventWithRv(3, EventType::TCP_SOCKET_CONNECT, net::OK); |
227 logger_->LogSocketEventWithRv(3, EventType::TCP_SOCKET_CONNECT, net::OK); | 63 last_errors = logger->GetLastErrors(3); |
228 last_errors = logger_->GetLastErrors(3); | |
229 EXPECT_EQ(last_errors.event_type, proto::AUTH_CHALLENGE_REPLY); | 64 EXPECT_EQ(last_errors.event_type, proto::AUTH_CHALLENGE_REPLY); |
230 EXPECT_EQ(last_errors.challenge_reply_error_type, | 65 EXPECT_EQ(last_errors.challenge_reply_error_type, |
231 proto::CHALLENGE_REPLY_ERROR_WRONG_PAYLOAD_TYPE); | 66 proto::CHALLENGE_REPLY_ERROR_WRONG_PAYLOAD_TYPE); |
232 } | 67 } |
233 | 68 |
234 TEST_F(CastChannelLoggerTest, LogSocketReadWrite) { | |
235 logger_->LogSocketEventWithRv(1, EventType::SOCKET_READ, 50); | |
236 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
237 logger_->LogSocketEventWithRv(1, EventType::SOCKET_READ, 30); | |
238 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
239 logger_->LogSocketEventWithRv(1, EventType::SOCKET_READ, -1); | |
240 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
241 logger_->LogSocketEventWithRv(1, EventType::SOCKET_WRITE, 20); | |
242 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
243 | |
244 logger_->LogSocketEventWithRv(2, EventType::SOCKET_READ, 100); | |
245 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
246 logger_->LogSocketEventWithRv(2, EventType::SOCKET_WRITE, 100); | |
247 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
248 logger_->LogSocketEventWithRv(2, EventType::SOCKET_WRITE, -5); | |
249 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
250 | |
251 std::unique_ptr<Log> log = GetLog(); | |
252 ASSERT_TRUE(log); | |
253 | |
254 ASSERT_EQ(2, log->aggregated_socket_event_size()); | |
255 { | |
256 const AggregatedSocketEvent& aggregated_socket_event = | |
257 log->aggregated_socket_event(0); | |
258 EXPECT_EQ(1, aggregated_socket_event.id()); | |
259 EXPECT_EQ(4, aggregated_socket_event.socket_event_size()); | |
260 EXPECT_EQ(80, aggregated_socket_event.bytes_read()); | |
261 EXPECT_EQ(20, aggregated_socket_event.bytes_written()); | |
262 } | |
263 { | |
264 const AggregatedSocketEvent& aggregated_socket_event = | |
265 log->aggregated_socket_event(1); | |
266 EXPECT_EQ(2, aggregated_socket_event.id()); | |
267 EXPECT_EQ(3, aggregated_socket_event.socket_event_size()); | |
268 EXPECT_EQ(100, aggregated_socket_event.bytes_read()); | |
269 EXPECT_EQ(100, aggregated_socket_event.bytes_written()); | |
270 } | |
271 } | |
272 | |
273 TEST_F(CastChannelLoggerTest, TooManySockets) { | |
274 for (int i = 0; i < kMaxSocketsToLog + 5; i++) { | |
275 logger_->LogSocketEvent(i, EventType::CAST_SOCKET_CREATED); | |
276 } | |
277 | |
278 std::unique_ptr<Log> log = GetLog(); | |
279 ASSERT_TRUE(log); | |
280 | |
281 ASSERT_EQ(kMaxSocketsToLog, log->aggregated_socket_event_size()); | |
282 EXPECT_EQ(5, log->num_evicted_aggregated_socket_events()); | |
283 EXPECT_EQ(5, log->num_evicted_socket_events()); | |
284 | |
285 const AggregatedSocketEvent& aggregated_socket_event = | |
286 log->aggregated_socket_event(0); | |
287 EXPECT_EQ(5, aggregated_socket_event.id()); | |
288 } | |
289 | |
290 TEST_F(CastChannelLoggerTest, TooManyEvents) { | |
291 for (int i = 0; i < kMaxEventsPerSocket + 5; i++) { | |
292 logger_->LogSocketEvent(1, EventType::CAST_SOCKET_CREATED); | |
293 clock_->Advance(base::TimeDelta::FromMicroseconds(1)); | |
294 } | |
295 | |
296 std::unique_ptr<Log> log = GetLog(); | |
297 ASSERT_TRUE(log); | |
298 | |
299 ASSERT_EQ(1, log->aggregated_socket_event_size()); | |
300 EXPECT_EQ(0, log->num_evicted_aggregated_socket_events()); | |
301 EXPECT_EQ(5, log->num_evicted_socket_events()); | |
302 | |
303 const AggregatedSocketEvent& aggregated_socket_event = | |
304 log->aggregated_socket_event(0); | |
305 ASSERT_EQ(kMaxEventsPerSocket, aggregated_socket_event.socket_event_size()); | |
306 EXPECT_EQ(5, aggregated_socket_event.socket_event(0).timestamp_micros()); | |
307 } | |
308 | |
309 TEST_F(CastChannelLoggerTest, Reset) { | |
310 logger_->LogSocketEvent(1, EventType::CAST_SOCKET_CREATED); | |
311 | |
312 std::unique_ptr<Log> log = GetLog(); | |
313 ASSERT_TRUE(log); | |
314 | |
315 EXPECT_EQ(1, log->aggregated_socket_event_size()); | |
316 | |
317 logger_->Reset(); | |
318 | |
319 log = GetLog(); | |
320 ASSERT_TRUE(log); | |
321 | |
322 EXPECT_EQ(0, log->aggregated_socket_event_size()); | |
323 } | |
324 | |
325 } // namespace cast_channel | 69 } // namespace cast_channel |
326 } // namespace api | 70 } // namespace api |
327 } // namespace extensions | 71 } // namespace extensions |
OLD | NEW |