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 "extensions/browser/api/cast_channel/logger.h" | 5 #include "extensions/browser/api/cast_channel/logger.h" |
6 | 6 |
7 #include <stdint.h> | 7 #include <stdint.h> |
8 | 8 |
9 #include <string> | 9 #include <string> |
10 #include <utility> | 10 #include <utility> |
11 | 11 |
12 #include "base/memory/ptr_util.h" | 12 #include "base/memory/ptr_util.h" |
13 #include "base/strings/string_util.h" | 13 #include "base/strings/string_util.h" |
14 #include "base/time/clock.h" | |
15 #include "extensions/browser/api/cast_channel/cast_auth_util.h" | 14 #include "extensions/browser/api/cast_channel/cast_auth_util.h" |
16 #include "extensions/browser/api/cast_channel/cast_socket.h" | 15 #include "extensions/browser/api/cast_channel/cast_socket.h" |
17 #include "extensions/browser/api/cast_channel/logger_util.h" | |
18 #include "net/base/net_errors.h" | 16 #include "net/base/net_errors.h" |
19 #include "third_party/zlib/zlib.h" | |
20 | 17 |
21 namespace extensions { | 18 namespace extensions { |
22 namespace api { | 19 namespace api { |
23 namespace cast_channel { | 20 namespace cast_channel { |
24 | 21 |
25 using net::IPEndPoint; | 22 using net::IPEndPoint; |
26 using proto::AggregatedSocketEvent; | |
27 using proto::EventType; | 23 using proto::EventType; |
28 using proto::Log; | 24 using proto::Log; |
29 using proto::SocketEvent; | 25 using proto::SocketEvent; |
30 | 26 |
31 namespace { | 27 namespace { |
32 | 28 |
33 const char kInternalNamespacePrefix[] = "com.google.cast"; | |
34 | |
35 proto::ChallengeReplyErrorType ChallegeReplyErrorToProto( | 29 proto::ChallengeReplyErrorType ChallegeReplyErrorToProto( |
36 AuthResult::ErrorType error_type) { | 30 AuthResult::ErrorType error_type) { |
37 switch (error_type) { | 31 switch (error_type) { |
38 case AuthResult::ERROR_NONE: | 32 case AuthResult::ERROR_NONE: |
39 return proto::CHALLENGE_REPLY_ERROR_NONE; | 33 return proto::CHALLENGE_REPLY_ERROR_NONE; |
40 case AuthResult::ERROR_PEER_CERT_EMPTY: | 34 case AuthResult::ERROR_PEER_CERT_EMPTY: |
41 return proto::CHALLENGE_REPLY_ERROR_PEER_CERT_EMPTY; | 35 return proto::CHALLENGE_REPLY_ERROR_PEER_CERT_EMPTY; |
42 case AuthResult::ERROR_WRONG_PAYLOAD_TYPE: | 36 case AuthResult::ERROR_WRONG_PAYLOAD_TYPE: |
43 return proto::CHALLENGE_REPLY_ERROR_WRONG_PAYLOAD_TYPE; | 37 return proto::CHALLENGE_REPLY_ERROR_WRONG_PAYLOAD_TYPE; |
44 case AuthResult::ERROR_NO_PAYLOAD: | 38 case AuthResult::ERROR_NO_PAYLOAD: |
(...skipping 23 matching lines...) Expand all Loading... | |
68 case AuthResult::ERROR_CRL_INVALID: | 62 case AuthResult::ERROR_CRL_INVALID: |
69 return proto::CHALLENGE_REPLY_ERROR_CRL_INVALID; | 63 return proto::CHALLENGE_REPLY_ERROR_CRL_INVALID; |
70 case AuthResult::ERROR_CERT_REVOKED: | 64 case AuthResult::ERROR_CERT_REVOKED: |
71 return proto::CHALLENGE_REPLY_ERROR_CERT_REVOKED; | 65 return proto::CHALLENGE_REPLY_ERROR_CERT_REVOKED; |
72 default: | 66 default: |
73 NOTREACHED(); | 67 NOTREACHED(); |
74 return proto::CHALLENGE_REPLY_ERROR_NONE; | 68 return proto::CHALLENGE_REPLY_ERROR_NONE; |
75 } | 69 } |
76 } | 70 } |
77 | 71 |
78 std::unique_ptr<char[]> Compress(const std::string& input, size_t* length) { | |
79 *length = 0; | |
80 z_stream stream = {0}; | |
81 int result = deflateInit2(&stream, | |
82 Z_DEFAULT_COMPRESSION, | |
83 Z_DEFLATED, | |
84 // 16 is added to produce a gzip header + trailer. | |
85 MAX_WBITS + 16, | |
86 8, // memLevel = 8 is default. | |
87 Z_DEFAULT_STRATEGY); | |
88 DCHECK_EQ(Z_OK, result); | |
89 | |
90 size_t out_size = deflateBound(&stream, input.size()); | |
91 std::unique_ptr<char[]> out(new char[out_size]); | |
92 | |
93 stream.next_in = reinterpret_cast<uint8_t*>(const_cast<char*>(input.data())); | |
94 stream.avail_in = input.size(); | |
95 stream.next_out = reinterpret_cast<uint8_t*>(out.get()); | |
96 stream.avail_out = out_size; | |
97 | |
98 // Do a one-shot compression. This will return Z_STREAM_END only if |output| | |
99 // is large enough to hold all compressed data. | |
100 result = deflate(&stream, Z_FINISH); | |
101 | |
102 bool success = (result == Z_STREAM_END); | |
103 | |
104 if (!success) | |
105 VLOG(2) << "deflate() failed. Result: " << result; | |
106 | |
107 result = deflateEnd(&stream); | |
108 DCHECK(result == Z_OK || result == Z_DATA_ERROR); | |
109 | |
110 if (success) | |
111 *length = out_size - stream.avail_out; | |
112 | |
113 return out; | |
114 } | |
115 | |
116 // Propagate any error fields set in |event| to |last_errors|. If any error | 72 // Propagate any error fields set in |event| to |last_errors|. If any error |
117 // field in |event| is set, then also set |last_errors->event_type|. | 73 // field in |event| is set, then also set |last_errors->event_type|. |
118 void MaybeSetLastErrors(const SocketEvent& event, LastErrors* last_errors) { | 74 void MaybeSetLastErrors(const SocketEvent& event, LastErrors* last_errors) { |
119 if (event.has_net_return_value() && | 75 if (event.has_net_return_value() && |
120 event.net_return_value() < net::ERR_IO_PENDING) { | 76 event.net_return_value() < net::ERR_IO_PENDING) { |
121 last_errors->net_return_value = event.net_return_value(); | 77 last_errors->net_return_value = event.net_return_value(); |
122 last_errors->event_type = event.type(); | 78 last_errors->event_type = event.type(); |
123 } | 79 } |
124 if (event.has_challenge_reply_error_type()) { | 80 if (event.has_challenge_reply_error_type()) { |
125 last_errors->challenge_reply_error_type = | 81 last_errors->challenge_reply_error_type = |
126 event.challenge_reply_error_type(); | 82 event.challenge_reply_error_type(); |
127 last_errors->event_type = event.type(); | 83 last_errors->event_type = event.type(); |
128 } | 84 } |
129 } | 85 } |
130 | 86 |
131 } // namespace | 87 } // namespace |
132 | 88 |
133 Logger::AggregatedSocketEventLog::AggregatedSocketEventLog() { | 89 LastErrors::LastErrors() |
134 } | 90 : event_type(proto::EVENT_TYPE_UNKNOWN), |
91 challenge_reply_error_type(proto::CHALLENGE_REPLY_ERROR_NONE), | |
92 net_return_value(net::OK) {} | |
135 | 93 |
136 Logger::AggregatedSocketEventLog::~AggregatedSocketEventLog() { | 94 LastErrors::~LastErrors() {} |
137 } | |
138 | 95 |
139 Logger::Logger(std::unique_ptr<base::Clock> clock, base::Time unix_epoch_time) | 96 Logger::Logger() { |
140 : clock_(std::move(clock)), unix_epoch_time_(unix_epoch_time) { | |
141 DCHECK(clock_); | |
142 | |
143 // Logger may not be necessarily be created on the IO thread, but logging | 97 // Logger may not be necessarily be created on the IO thread, but logging |
144 // happens exclusively there. | 98 // happens exclusively there. |
145 thread_checker_.DetachFromThread(); | 99 thread_checker_.DetachFromThread(); |
146 } | 100 } |
147 | 101 |
148 Logger::~Logger() { | 102 Logger::~Logger() { |
149 } | 103 } |
150 | 104 |
151 void Logger::LogNewSocketEvent(const CastSocket& cast_socket) { | |
152 DCHECK(thread_checker_.CalledOnValidThread()); | |
153 | |
154 SocketEvent event = CreateEvent(proto::CAST_SOCKET_CREATED); | |
155 AggregatedSocketEvent& aggregated_socket_event = | |
156 LogSocketEvent(cast_socket.id(), event); | |
157 | |
158 const net::IPAddress& ip = cast_socket.ip_endpoint().address(); | |
159 DCHECK(ip.IsValid()); | |
160 aggregated_socket_event.set_endpoint_id(ip.bytes().back()); | |
161 aggregated_socket_event.set_channel_auth_type(proto::SSL_VERIFIED); | |
162 } | |
163 | |
164 void Logger::LogSocketEvent(int channel_id, EventType event_type) { | |
165 DCHECK(thread_checker_.CalledOnValidThread()); | |
166 | |
167 LogSocketEventWithDetails(channel_id, event_type, std::string()); | |
168 } | |
169 | |
170 void Logger::LogSocketEventWithDetails(int channel_id, | |
171 EventType event_type, | |
172 const std::string& details) { | |
173 DCHECK(thread_checker_.CalledOnValidThread()); | |
174 | |
175 SocketEvent event = CreateEvent(event_type); | |
176 if (!details.empty()) | |
177 event.set_details(details); | |
178 | |
179 LogSocketEvent(channel_id, event); | |
180 } | |
181 | |
182 void Logger::LogSocketEventWithRv(int channel_id, | 105 void Logger::LogSocketEventWithRv(int channel_id, |
183 EventType event_type, | 106 EventType event_type, |
184 int rv) { | 107 int rv) { |
185 DCHECK(thread_checker_.CalledOnValidThread()); | 108 DCHECK(thread_checker_.CalledOnValidThread()); |
186 | 109 |
187 SocketEvent event = CreateEvent(event_type); | 110 SocketEvent event = CreateEvent(event_type); |
188 event.set_net_return_value(rv); | 111 event.set_net_return_value(rv); |
189 | 112 |
190 AggregatedSocketEvent& aggregated_socket_event = | |
191 LogSocketEvent(channel_id, event); | |
192 | |
193 if ((event_type == proto::SOCKET_READ || event_type == proto::SOCKET_WRITE) && | |
194 rv > 0) { | |
195 if (event_type == proto::SOCKET_READ) { | |
196 aggregated_socket_event.set_bytes_read( | |
197 aggregated_socket_event.bytes_read() + rv); | |
198 } else { | |
199 aggregated_socket_event.set_bytes_written( | |
200 aggregated_socket_event.bytes_written() + rv); | |
201 } | |
202 } | |
203 } | |
204 | |
205 void Logger::LogSocketReadyState(int channel_id, proto::ReadyState new_state) { | |
206 DCHECK(thread_checker_.CalledOnValidThread()); | |
207 | |
208 SocketEvent event = CreateEvent(proto::READY_STATE_CHANGED); | |
209 event.set_ready_state(new_state); | |
210 | |
211 LogSocketEvent(channel_id, event); | 113 LogSocketEvent(channel_id, event); |
212 } | 114 } |
213 | 115 |
214 void Logger::LogSocketConnectState(int channel_id, | |
215 proto::ConnectionState new_state) { | |
216 DCHECK(thread_checker_.CalledOnValidThread()); | |
217 | |
218 SocketEvent event = CreateEvent(proto::CONNECTION_STATE_CHANGED); | |
219 event.set_connection_state(new_state); | |
220 | |
221 LogSocketEvent(channel_id, event); | |
222 } | |
223 | |
224 void Logger::LogSocketReadState(int channel_id, proto::ReadState new_state) { | |
225 DCHECK(thread_checker_.CalledOnValidThread()); | |
226 | |
227 SocketEvent event = CreateEvent(proto::READ_STATE_CHANGED); | |
228 event.set_read_state(new_state); | |
229 | |
230 LogSocketEvent(channel_id, event); | |
231 } | |
232 | |
233 void Logger::LogSocketWriteState(int channel_id, proto::WriteState new_state) { | |
234 DCHECK(thread_checker_.CalledOnValidThread()); | |
235 | |
236 SocketEvent event = CreateEvent(proto::WRITE_STATE_CHANGED); | |
237 event.set_write_state(new_state); | |
238 | |
239 LogSocketEvent(channel_id, event); | |
240 } | |
241 | |
242 void Logger::LogSocketErrorState(int channel_id, proto::ErrorState new_state) { | |
243 DCHECK(thread_checker_.CalledOnValidThread()); | |
244 | |
245 SocketEvent event = CreateEvent(proto::ERROR_STATE_CHANGED); | |
246 event.set_error_state(new_state); | |
247 | |
248 LogSocketEvent(channel_id, event); | |
249 } | |
250 | |
251 void Logger::LogSocketEventForMessage(int channel_id, | |
252 EventType event_type, | |
253 const std::string& message_namespace, | |
254 const std::string& details) { | |
255 DCHECK(thread_checker_.CalledOnValidThread()); | |
256 | |
257 SocketEvent event = CreateEvent(event_type); | |
258 if (base::StartsWith(message_namespace, kInternalNamespacePrefix, | |
259 base::CompareCase::INSENSITIVE_ASCII)) | |
260 event.set_message_namespace(message_namespace); | |
261 event.set_details(details); | |
262 | |
263 LogSocketEvent(channel_id, event); | |
264 } | |
265 | |
266 void Logger::LogSocketChallengeReplyEvent(int channel_id, | 116 void Logger::LogSocketChallengeReplyEvent(int channel_id, |
267 const AuthResult& auth_result) { | 117 const AuthResult& auth_result) { |
268 DCHECK(thread_checker_.CalledOnValidThread()); | 118 DCHECK(thread_checker_.CalledOnValidThread()); |
269 | 119 |
270 SocketEvent event = CreateEvent(proto::AUTH_CHALLENGE_REPLY); | 120 SocketEvent event = CreateEvent(proto::AUTH_CHALLENGE_REPLY); |
271 event.set_challenge_reply_error_type( | 121 event.set_challenge_reply_error_type( |
272 ChallegeReplyErrorToProto(auth_result.error_type)); | 122 ChallegeReplyErrorToProto(auth_result.error_type)); |
273 | 123 |
274 LogSocketEvent(channel_id, event); | 124 LogSocketEvent(channel_id, event); |
275 } | 125 } |
276 | 126 |
127 LastErrors Logger::GetLastErrors(int channel_id) const { | |
128 LastErrorsMap::const_iterator it = last_errors_.find(channel_id); | |
129 if (it != last_errors_.end()) { | |
130 return it->second; | |
131 } else { | |
132 return LastErrors(); | |
133 } | |
134 } | |
135 | |
136 void Logger::ClearLastErrors(int channel_id) { | |
137 last_errors_.erase(channel_id); | |
138 } | |
139 | |
277 SocketEvent Logger::CreateEvent(EventType event_type) { | 140 SocketEvent Logger::CreateEvent(EventType event_type) { |
278 SocketEvent event; | 141 SocketEvent event; |
279 event.set_type(event_type); | 142 event.set_type(event_type); |
280 event.set_timestamp_micros( | |
281 (clock_->Now() - unix_epoch_time_).InMicroseconds()); | |
282 return event; | 143 return event; |
283 } | 144 } |
284 | 145 |
285 AggregatedSocketEvent& Logger::LogSocketEvent(int channel_id, | 146 void Logger::LogSocketEvent(int channel_id, const SocketEvent& socket_event) { |
286 const SocketEvent& socket_event) { | 147 LastErrorsMap::iterator it = last_errors_.find(channel_id); |
287 AggregatedSocketEventLogMap::iterator it = | 148 if (it == last_errors_.end()) |
288 aggregated_socket_events_.find(channel_id); | 149 last_errors_[channel_id] = LastErrors(); |
289 if (it == aggregated_socket_events_.end()) { | |
290 if (aggregated_socket_events_.size() >= kMaxSocketsToLog) { | |
291 AggregatedSocketEventLogMap::iterator erase_it = | |
292 aggregated_socket_events_.begin(); | |
293 | 150 |
294 log_.set_num_evicted_aggregated_socket_events( | 151 MaybeSetLastErrors(socket_event, &last_errors_[channel_id]); |
Kevin M
2017/02/09 19:28:54
Since this only makes changes for errors now, can
mark a. foltz
2017/02/10 21:55:16
Done, in places which didn't complicate the callin
| |
295 log_.num_evicted_aggregated_socket_events() + 1); | |
296 log_.set_num_evicted_socket_events( | |
297 log_.num_evicted_socket_events() + | |
298 erase_it->second->socket_events.size()); | |
299 | |
300 aggregated_socket_events_.erase(erase_it); | |
301 } | |
302 | |
303 it = aggregated_socket_events_ | |
304 .insert(std::make_pair( | |
305 channel_id, base::MakeUnique<AggregatedSocketEventLog>())) | |
306 .first; | |
307 it->second->aggregated_socket_event.set_id(channel_id); | |
308 } | |
309 | |
310 std::deque<proto::SocketEvent>& socket_events = it->second->socket_events; | |
311 if (socket_events.size() >= kMaxEventsPerSocket) { | |
312 socket_events.pop_front(); | |
313 log_.set_num_evicted_socket_events(log_.num_evicted_socket_events() + 1); | |
314 } | |
315 socket_events.push_back(socket_event); | |
316 | |
317 MaybeSetLastErrors(socket_event, &(it->second->last_errors)); | |
318 | |
319 return it->second->aggregated_socket_event; | |
320 } | |
321 | |
322 std::unique_ptr<char[]> Logger::GetLogs(size_t* length) const { | |
323 *length = 0; | |
324 | |
325 Log log; | |
326 // Copy "global" values from |log_|. Don't use |log_| directly since this | |
327 // function is const. | |
328 log.CopyFrom(log_); | |
329 | |
330 for (AggregatedSocketEventLogMap::const_iterator it = | |
331 aggregated_socket_events_.begin(); | |
332 it != aggregated_socket_events_.end(); | |
333 ++it) { | |
334 AggregatedSocketEvent* new_aggregated_socket_event = | |
335 log.add_aggregated_socket_event(); | |
336 new_aggregated_socket_event->CopyFrom(it->second->aggregated_socket_event); | |
337 | |
338 const std::deque<SocketEvent>& socket_events = it->second->socket_events; | |
339 for (std::deque<SocketEvent>::const_iterator socket_event_it = | |
340 socket_events.begin(); | |
341 socket_event_it != socket_events.end(); | |
342 ++socket_event_it) { | |
343 SocketEvent* socket_event = | |
344 new_aggregated_socket_event->add_socket_event(); | |
345 socket_event->CopyFrom(*socket_event_it); | |
346 } | |
347 } | |
348 | |
349 std::string serialized; | |
350 if (!log.SerializeToString(&serialized)) { | |
351 VLOG(2) << "Failed to serialized proto to string."; | |
352 return std::unique_ptr<char[]>(); | |
353 } | |
354 | |
355 return Compress(serialized, length); | |
356 } | |
357 | |
358 void Logger::Reset() { | |
359 aggregated_socket_events_.clear(); | |
360 log_.Clear(); | |
361 } | |
362 | |
363 LastErrors Logger::GetLastErrors(int channel_id) const { | |
364 AggregatedSocketEventLogMap::const_iterator it = | |
365 aggregated_socket_events_.find(channel_id); | |
366 if (it != aggregated_socket_events_.end()) { | |
367 return it->second->last_errors; | |
368 } else { | |
369 return LastErrors(); | |
370 } | |
371 } | 152 } |
372 | 153 |
373 } // namespace cast_channel | 154 } // namespace cast_channel |
374 } // namespace api | 155 } // namespace api |
375 } // namespace extensions | 156 } // namespace extensions |
OLD | NEW |